22 May
2012
22 May
'12
7:50 a.m.
On Tue, May 22, 2012 at 5:41 PM, Daniel-Constantin Mierla
<miconda(a)gmail.com> wrote:
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
Hi Daniel,
Thanks for the reply.
We have already came to the same conclusion by some testing in our
lab. It seems its a bug in provider which not constructing BYE message
properly.
But i'm interested in if its possible to detect the fault in this BYE
and construct a new one and then relay it to the UAC.
I mean can i do this :
contact-header = INVITE's contact-header
if (contact-header != BYE's ruri)
{
construct BYE message with contact header
t_relay()
}
Cheers
aft
On 5/21/12 9:21 PM, Arif Hossain wrote:
--
-aft
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@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@205.164.40.74;tag=100528120745985872655137
Call-ID: IqBknV19AuxW0jk.8BjuE4hyx93Ws9qS
To: "123456"
<sip:ipphone@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@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@205.164.40.74;tag=100528120745985872655137
Call-ID: IqBknV19AuxW0jk.8BjuE4hyx93Ws9qS
To: "123456"
<sip:ipphone@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@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@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@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