[Freeswitch-users] BYE message is not relayed to the UAC
Michael Collins
msc at freeswitch.org
Mon May 21 20:22:05 MSD 2012
Your best bet is to use a pastebin for this sort of thing. The FreeSWITCH
project maintains their own at pastebin.freeswitch.org. There are numerous
others (pastie, pastebin.com, etc.) After you put all the information in a
pastebin you'll get a handy URL that you can include in the email thread.
One other advantage to pastebins is that you can refer to a specific line
number in paste. ("Look at the BYE message at line xxx - it looks
unusual...")
-MC
On Mon, May 21, 2012 at 12:26 AM, Arif Hossain <aftnix at gmail.com> wrote:
> Hi,
>
> We have the following network architecture :
>
>
> UAC1------------------------->kamailio-------------------->VoipSwitch----->PSTN---------->Phone1
> (Sip Client)
>
> Now UAC1 calls Phone1 and everything is ok. If UAC1 hangs up session
> is terminated cleanly.
> But if Phone1 hangs up the BYE message which comes to kamailio and
> goes back to VoipSwitch
> instead of relayed to UAC1 .
>
> So The session becomes a zombie one, And UAC1 unfortunately gets
> billed for a session
> which should be terminated.
>
> Following is the Call flow as seen from VoipSwitch :
>
> | <kamilio IP> |
> | | | <VoipSwitch
> IP> |
> |134.856 | INVITE SDP
> | |(7890) ------------------> (5060) |
> |134.858 | 407 Proxy Authentication Required
> | |(7890) <------------------ (5060) |
> |134.902 | ACK |
> | |(7890) ------------------> (5060) |
> |135.408 | INVITE SDP
> | |(7890) ------------------> (5060) |
> |135.414 | 100 Trying|
> | |(7890) <------------------ (5060) |
> |140.121 | 183 Session Progress SDP
> | |(7890) <------------------ (5060) |
> |140.184 | RTP (g729) |
> | |(61868) <------------------ (5136) |
> |141.295 | RTP (g729) |
> | |(61868) ------------------> (5136) |
> |153.701 | 200 OK SDP
> | |(7890) <------------------ (5060) |
> |153.713 | RTP (g729) |
> | |(61868) ------------------> (5136) |
> |154.126 | ACK |
> | |(7890) ------------------> (5060) |
> |159.988 | BYE |
> | |(7890) <------------------ (5060) |
> |160.031 | BYE |
> | |(7890) ------------------> (5060) |
> |160.478 | BYE |
> | |(7890) ------------------> (5060) |
> |161.412 | BYE |
> | |(7890) ------------------> (5060) |
> |163.280 | BYE |
> | |(7890) ------------------> (5060) |
> |167.015 | BYE |
> | |(7890) ------------------> (5060) |
> |170.750 | BYE |
> | |(7890) ------------------> (5060) |
> |174.481 | BYE |
> | |(7890) ------------------> (5060) |
> |178.216 | BYE |
> | |(7890) ------------------> (5060) |
> |181.952 | BYE |
> | |(7890) ------------------> (5060) |
> |185.687 | BYE |
> | |(7890) ------------------> (5060) |
> |188.018 | 408 Request Timeout
> | |(7890) ------------------> (5060) |
> |211.849 | BYE |
> | |(7890) ------------------> (5060) |
> |212.292 | BYE |
>
>
> Sip Traces :
>
> kamailio------>VoipSwitch
>
> I'm posting only the offending BYE msg instead of full trace , because
> of the mail will become difficult to read . If more traces needed, i
> can post it.
>
> The following BYE message is sent by VoipSwitch:
>
> BYE sip:ipphone at 205.164.40.74 SIP/2.0
> Route: <sip:108.166.195.189:7890;lr=on;nat=yes>
> CSeq: 2 BYE
> Via: SIP/2.0/UDP 205.164.40.74:5060
> From: sip:008801673345531 at 205.164.40.74;tag=100528120745985872655137
> Call-ID: IqBknV19AuxW0jk.8BjuE4hyx93Ws9qS
> To: "123456" <sip:ipphone at 205.164.40.74
> >;tag=Zopl5lj5YiqyaSR5Le3QnfoR-G0NZAGG
> Content-Length: 0
>
> Kamailio instead of relaying the message, sends a BYE message towards
> VoipSwitch:
>
> BYE sip:ipphone at 205.164.40.74 SIP/2.0
> Max-Forwards: 10
> CSeq: 2 BYE
> Via: SIP/2.0/UDP 108.166.195.189:7890;branch=z9hG4bK4b2b.5d893e95.0
> Via: SIP/2.0/UDP 205.164.40.74:5060;rport=5060
> From: sip:008801673345531 at 205.164.40.74;tag=100528120745985872655137
> Call-ID: IqBknV19AuxW0jk.8BjuE4hyx93Ws9qS
> To: "123456" <sip:ipphone at 205.164.40.74
> >;tag=Zopl5lj5YiqyaSR5Le3QnfoR-G0NZAGG
> Content-Length: 0
>
> When the first BYE message comes from VoipSwitch , kamailio does the
> following :
> May 20 02:25:53 VOS20-108 /usr/local/sbin/kamailio[16442]: DEBUG:
> <core> [receive.c:289]: receive_msg: cleaning up
> May 20 02:25:53 VOS20-108 /usr/local/sbin/kamailio[16442]: DEBUG:
> <core> [parser/sdp/sdp.c:751]: _sdp = 0x831bf10
> May 20 02:25:53 VOS20-108 /usr/local/sbin/kamailio[16442]: DEBUG:
> <core> [parser/sdp/sdp.c:753]: sdp = 0x83043dc
> May 20 02:25:53 VOS20-108 /usr/local/sbin/kamailio[16442]: DEBUG:
> <core> [parser/sdp/sdp.c:755]: session = 0x8304504
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:630]: SIP Request:
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:632]: method: <BYE>
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:634]: uri:
> <sip:ipphone at 205.164.40.74>
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:636]: version: <SIP/2.0>
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:167]: get_hdr_field: cseq <CSeq>: <1>
> <BYE>
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/parse_via.c:1287]: Found param type 232, <branch> =
> <z9hG4bk19052612230719933454843>; state=16
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/parse_via.c:2300]: end of header reached, state=5
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:515]: parse_headers: Via found, flags=2
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:517]: parse_headers: this is the first via
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [receive.c:145]: After parse_msg...
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [receive.c:186]: preparing to run routing scripts...
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/parse_to.c:174]: DEBUG: add_param:
> tag=arILprdVR1srJ76HHlt4BEc3XsyaWcZm
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/parse_to.c:803]: end of header reached, state=29
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:187]: DEBUG: get_hdr_field: <To> [76];
> uri=[sip:ipphone at 205.164.40.74]
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:189]: DEBUG: to body ["ipphone"
> <sip:ipphone at 205.164.40.74>]
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:201]: DEBUG: get_hdr_body :
> content_length=0
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:103]: found end of header
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> maxfwd [mf_funcs.c:66]: max_forwards header not found!
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/parse_to.c:174]: DEBUG: add_param:
> tag=1905251223419334290936029
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/parse_to.c:803]: end of header reached, state=29
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> siputils [checks.c:76]: totag found
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: rr
> [loose.c:85]: is_preloaded: No
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [socket_info.c:501]: grep_sock_info - checking if host==us:
> 13==15 && [205.164.40.74] == [108.166.195.189]
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [socket_info.c:504]: grep_sock_info - checking if port 7890
> matches port 5060
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [socket_info.c:501]: grep_sock_info - checking if host==us:
> 13==15 && [205.164.40.74] == [108.166.195.189]
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [socket_info.c:504]: grep_sock_info - checking if port 5060
> matches port 5060
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [forward.c:448]: check_self: host != me
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [socket_info.c:501]: grep_sock_info - checking if host==us:
> 15==15 && [108.166.195.189] == [108.166.195.189]
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [socket_info.c:504]: grep_sock_info - checking if port 7890
> matches port 7890
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: rr
> [loose.c:792]: Topmost route URI:
> 'sip:108.166.195.189:7890;lr=on;nat=yes' is me
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [parser/msg_parser.c:103]: found end of header
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: rr
> [loose.c:257]: No next Route HF found
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: rr
> [loose.c:811]: No next URI found
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: rr
> [loose.c:983]: params are <;lr=on;nat=yes>
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> siputils [checks.c:76]: totag found
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: tm
> [t_lookup.c:1379]: DEBUG: t_newtran: msg id=2501 , global msg id=2500
> , T on entrance=0xffffffff
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: tm
> [t_lookup.c:528]: t_lookup_request: start searching: hash=29177,
> isACK=0
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: tm
> [t_lookup.c:564]: DEBUG: proceeding to pre-RFC3261 transaction
> matching
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: tm
> [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: tm
> [t_hooks.c:374]: DBG: trans=0xb61626a4, callback type 1, id 0 entered
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [msg_translator.c:204]: check_via_address(205.164.40.74,
> 205.164.40.74, 0)
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG: tm
> [t_funcs.c:388]: SER: new transaction fwd'ed
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
> May 20 02:26:04 VOS20-108 last message repeated 5 times
> May 20 02:26:04 VOS20-108 /usr/local/sbin/kamailio[16443]: DEBUG:
> <core> [receive.c:289]: receive_msg: cleaning up
> May 20 02:26:22 VOS20-108 /usr/local/sbin/kamailio[16445]: DEBUG:
> <core> [udp_server.c:486]: udp_rcv_loop: probing packet received from
> 180.234.62.230 38722
> May 20 02:26:34 VOS20-108 /usr/local/sbin/kamailio[16450]: DEBUG: tm
> [t_reply.c:1134]: ->>>>>>>>> T_code=0, new_code=408
> May 20 02:26:34 VOS20-108 /usr/local/sbin/kamailio[16450]: DEBUG: tm
> [t_reply.c:1636]: DEBUG: relay_reply: branch=0, save=0, relay=0
> May 20 02:26:34 VOS20-108 /usr/local/sbin/kamailio[16450]: DEBUG:
> <core> [msg_translator.c:204]: check_via_address(205.164.40.74,
> 205.164.40.74, 0)
> May 20 02:26:34 VOS20-108 /usr/local/sbin/kamailio[16450]: DEBUG:
> <core> [mem/shm_mem.c:105]: WARNING:vqm_resize: resize(0) called
> May 20 02:26:34 VOS20-108 /usr/local/sbin/kamailio[16450]: DEBUG: tm
> [t_hooks.c:288]: DBG: trans=0xb61626a4, callback type 128, id 0
> entered
> May 20 02:26:54 VOS20-108 /usr/local/sbin/kamailio[16451]: WARNING:
> <core> [timer.c:450]: WARNING: our timer runs faster then real-time
> (300000 ms / 4800 ticks our time .-> 299923 ms / 4798 ticks real time)
>
> OT: How do you guys maintain 80 column mails? i do not use a mail
> client, use gmail mailbox.
> --
> -aft
>
>
> --
> -aft
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> Join Us At ClueCon - Aug 7-9, 2012
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20120521/c171d15d/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users
mailing list