[Freeswitch-users] BYE message is not relayed to the UAC

Arif Hossain aftnix at gmail.com
Mon May 21 23:33:47 MSD 2012


On Mon, May 21, 2012 at 10:22 PM, Michael Collins <msc at freeswitch.org> wrote:
> 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
>

freeswitch's pastebin asks for authentication.


> 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
>
>
>
> _________________________________________________________________________
> 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
>



-- 
-aft



Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users mailing list