[SR-Users] kamailioi is not relaying BYE message to UAC
Daniel-Constantin Mierla
miconda at gmail.com
Tue May 22 13:41:28 CEST 2012
Hello,
is 205.164.40.74 the IP address of VoipSwitch? If yes, then the BYE is
constructed to be sent back to it, because the r-uri has this IP address.
R-uri in the BYE must have the IP address and port of UAC1.
If you give here all the sip trace for such call (from INVITE to the
BYE, taken with ngrep for example, on kamailio host), we may be able to
spot where the mistake is made. R-URI should be constructed from Contact
header of INVITE or 200ok.
Cheers,
Daniel
On 5/21/12 9:21 PM, Arif Hossain 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) |
> |181.952 | BYE |
> | |(7890) ------------------> (5060) |
> |185.687 | BYE |
> | |(7890) ------------------> (5060) |
> |188.018 | 408 Request Timeout
> | |(7890) ------------------> (5060) |
>
>
>
> 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.
>
--
Daniel-Constantin Mierla - http://www.asipto.com
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
More information about the sr-users
mailing list