[OpenSER-Users] Problems with BYE

Mon Jul 14 12:23:01 CEST 2008

Here's the output with debug 9 when doing BYE.

/Jan

Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: SIP Request:
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]:  method:  <BYE>
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]:  uri:     
<sip:07011221122 at vrt-ssw.sto.se.sn.net>
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]:  version: <SIP/2.0>
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: flags=2
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: Found param type 232, 
<branch> = <z9hG4bK-d87543-4f0b070e880e315a-1--d87543->; state=6
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: Found param type 235, 
<rport> = <n/a>; state=17
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: end of header reached, 
state=5
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: Via 
found, flags=2
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: this is 
the first via
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: After parse_msg...
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: preparing to run routing 
scripts...
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: flags=10
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: add_param: 
tag=8440b02f
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:parse_to:end of 
header reached, state=29
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DBUG:parse_to: 
display={"07011221122"}, ruri={sip:07011221122 at proxy3.digisip.net}
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: get_hdr_field: 
<To> [62]; uri=[sip:07011221122 at proxy3.digisip.net]
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: to body 
["07011221122"<sip:07011221122 at proxy3.digisip.net>]
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: add_param: 
tag=393efa4d
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:parse_to:end of 
header reached, state=29
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DBUG:parse_to: 
display={"0751223322"}, ruri={sip:0751223322 at proxy3.digisip.net}
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: flags=40
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: New request - M=BYE 
RURI=sip:07011221122 at vrt-ssw.sto.se.sn.net 
F=sip:0751223322 at proxy3.digisip.net T=sip:07011221122 at proxy3.digisip.net 
IP=82.209.164.203 ID=YTY4MmU4NGY2ZGIyZTE2ZTE2ZTYyOTk3Yzg3ZGY1ZjU.
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
DEBUG:maxfwd:is_maxfwd_present: value = 70
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
check_via_address(82.209.164.203, 10.45.0.98, 0)
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: flags=40
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: flags=200
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: is_preloaded: No
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: grep_sock_info - 
checking if host==us: 21==12 &&  [vrt-ssw.sto.se.sn.net] == [89.160.20.26]
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: grep_sock_info - 
checking if port 5060 matches port 5060
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: check_self: host != me
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: grep_sock_info - 
checking if host==us: 12==12 &&  [89.160.20.26] == [89.160.20.26]
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: grep_sock_info - 
checking if port 5060 matches port 5060
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: after_loose: Topmost 
route URI: 'sip:89.160.20.26;lr;ftag=393efa4d;nat=yes' is me
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: after_loose: URI to be 
processed: 'sip:sipgw.tdcsong.se;lr'
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: after_loose: Next URI is 
a loose router
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: has_totag: totag 
found
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
check_via_address(82.209.164.203, 10.45.0.98, 0)
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: flags=80
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: 
flags=ffffffffffffffff
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: get_hdr_field: cseq 
<CSeq>: <3> <BYE>
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: get_hdr_body : 
content_length=0
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: found end of header
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: consume_credentials(): 
No authorized credentials found (error in scripts)
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: Request leaving server, 
D-URI='sip:sipgw.tdcsong.se;lr' - M=BYE 
RURI=sip:07011221122 at vrt-ssw.sto.se.sn.net 
F=sip:0751223322 at proxy3.digisip.net T=sip:07011221122 at proxy3.digisip.net 
IP=82.209.164.203 ID=YTY4MmU4NGY2ZGIyZTE2ZTE2ZTYyOTk3Yzg3ZGY1ZjU.
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: t_newtran: msg 
id=4 , global msg id=3 , T on entrance=0xffffffff
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: 
flags=ffffffffffffffff
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: flags=78
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: t_lookup_request: start 
searching: hash=15179, isACK=0
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: RFC3261 
transaction matching failed
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: t_lookup_request: 
no transaction found
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: mk_proxy: doing 
DNS lookup...
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:sip_resolvehost2: 
no port, no proto -> do NAPTR lookup!
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
DEBUG:filter_and_sort_naptr: found valid SIPS+D2T -> 
_sips._tcp.sipgw.tdcsong.se
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
DEBUG:filter_and_sort_naptr: found valid SIP+D2T -> 
_sip._tcp.sipgw.tdcsong.se
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
DEBUG:filter_and_sort_naptr: found valid SIP+D2U -> 
_sip._udp.sipgw.tdcsong.se
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:do_srv_lookup: 
SRV(_sips._tcp.sipgw.tdcsong.se) = vrt-sipp.sipgw.tdcsong.se:5061
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:sip_resolvehost2: 
found!
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: ERROR:tm:add_uac: can't 
fwd to af 2, proto 2  (no corresponding listening socket)
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
ERROR:tm:t_forward_nonack: failure to add branches
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: ERROR:tm:t_relay_to:  
t_forward_nonack returned error
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: parse_headers: 
flags=ffffffffffffffff
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: 
check_via_address(82.209.164.203, 10.45.0.98, 0)
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: WARNING:vqm_resize: 
resize(0) called
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: 
cleanup_uac_timers: RETR/FR timers reset
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG: 
add_to_tail_of_timer[2]: 0xb3c96e78
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:tm:_reply_light: 
reply sent out. buf=0x8132ab0: SIP/2.0 5..., shmem=0xb3c990b8: SIP/2.0 5
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:tm:_reply_light: 
finished
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: ERROR: generation of a 
stateful reply on error succeeded
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:tm:UNREF_UNSAFE: 
after is 0
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: DEBUG:destroy_avp_list: 
destroying list (nil)
Jul 14 12:17:20 proxy /usr/sbin/openser[29489]: receive_msg: cleaning up
Jul 14 12:17:24 proxy /usr/sbin/openser[29498]: DEBUG: timer 
routine:2,tl=0xb3c96e78 next=(nil)
Jul 14 12:17:24 proxy /usr/sbin/openser[29498]: DEBUG: wait_handler : 
removing 0xb3c96e30 from table
Jul 14 12:17:24 proxy /usr/sbin/openser[29498]: DEBUG: delete 
transaction 0xb3c96e30
Jul 14 12:17:24 proxy /usr/sbin/openser[29498]: DEBUG: wait_handler : done
> Hi Jan,
>
> First check the syslog for more info on the error. OpenSER generated 
> an internal error because it was not able to send out the BYE request 
> (7 err code means no available socket).
>
> Regards,
> Bogdan
>
> Jan P wrote:
>> Hi,
>>
>> I made a pretty basic openser config with Sipwise but Im having 
>> problems when sending BYE to my upstream SIP provider. When I do a 
>> CANCEL it works but sending BYE the server doesnt forward any 
>> packets. Here's a ngrep of whats happening. My complete openser.cfg 
>> can be found at http://port53.se/openser.txt
>>
>> #
>> U 99.88.164.203:30824 -> 101.12.20.26:5060
>> BYE sip:0709955324 at bbr-ssw.sto.la.aa.net SIP/2.0.
>> Via: SIP/2.0/UDP 
>> 10.45.0.98:30824;branch=z9hG4bK-d87543-f13c745a11112e7c-1--d87543-;rport. 
>>
>> Max-Forwards: 70.
>> Route: <sip:101.12.20.26;lr;ftag=9a47eb12;nat=yes>.
>> Route: <sip:sipgw.sds.se;lr>.
>> Contact: <sip:0722465930 at 99.88.164.203:30824>.
>> To: "0709955324"<sip:0709955324 at proxy.realm.se>;tag=ecbc244f.
>> From: "0722465930"<sip:0722465930 at proxy.realm.se>;tag=9a47eb12.
>> Call-ID: ZDYwNjNjMmYzMTdiZGE3NTc4Nzc4OTA2NjdkOTllYTU..
>> CSeq: 3 BYE.
>> Proxy-Authorization: Digest 
>> username="30000",realm="proxy.realm.se",nonce="487473f9db3e3da3ae9c3115a6d87d2023cc6b0a",uri="sip:0709955324 at bbr-ssw.sto.la.aa.net",response="d9dc90e88deba0d9ba428bc11554b193",algorithm=MD5. 
>>
>> User-Agent: X-Lite release 1011s stamp 41150.
>> Reason: SIP;description="User Hung Up".
>> Content-Length: 0.
>> .
>>
>> #
>> U 101.12.20.26:5060 -> 99.88.164.203:30824
>> SIP/2.0 500 I'm terribly sorry, server error occurred (7/TM).
>> Via: SIP/2.0/UDP 
>> 10.45.0.98:30824;branch=z9hG4bK-d87543-f13c745a11112e7c-1--d87543-;rport=30824;received=99.88.164.203. 
>>
>> To: "0709955324"<sip:0709955324 at proxy3.digisip.net>;tag=ecbc244f.
>> From: "0722465930"<sip:0722465930 at proxy3.digisip.net>;tag=9a47eb12.
>> Call-ID: ZDYwNjNjMmYzMTdiZGE3NTc4Nzc4OTA2NjdkOTllYTU..
>> CSeq: 3 BYE.
>> Server: OpenSer (1.1.0-notls (i386/linux)).
>> Content-Length: 0.
>> .
>>
>> #
>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.openser.org
>> http://lists.openser.org/cgi-bin/mailman/listinfo/users
>>
>>   
>