[OpenSER-Users] Problems with BYE
Bogdan-Andrei Iancu
bogdan at voice-system.ro
Mon Jul 14 13:32:30 CEST 2008
Hi Jan,
The device following openser in the SIP path looks to be a GW and it
used a DNS name in the RR header. See in BYE:
Route: <sip:sipgw.sds.se;lr>.
Now, when openser wants to route the BYE to that address, it using
standard location discovery by using NAPTR and SRV lookups:
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)
but your GW advertises an TCP location which openser tries to use. Do
you have TCP enabled in openser? also, do you have any TCP interface
configured in openser?
I suspect TCP is on, but no TCP listen is set.
Regards,
Bogdan
Jan P wrote:
> 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
>>>
>>>
>>
>
>
More information about the sr-users
mailing list