Daniel-Constantin Mierla a écrit :
Hello,
On 12/04/08 12:48, Aurelien Grimaud wrote:
Hi,
I am running a rather old version of openser, but since in a
production context, I cannot upgrade anytime I want to catch up with
newer releases.
I searched bugs and googled for my problem without any result.
There it is.
I have a module with functions beginning with mn_
mn_received handle any incoming request and prints it out.
my module has a callback on response which prints out responses.
My configuration file is something like
// handle register
mn_received() ;
record_route() ;
if ( method=="INVITE")
{
t_on_failure(ROUTE_INVITE) ;
t_on_reply(ROUTE_INVITE) ;
}
Then the request is t_relayed to destination.
The onreply_route[ROUTE_INVITE] prints some output, and fix_contact
on 200, ... whatever.
Then this happens :
- An INVITE is received from A (I see it with mn_received)
- INVITE is relayed to destination B
- B replies 180, I see the response on my module output and I see my
onreply_route[INVITE] statements.
- B replies 200, I see the response on my module output, but, I *do
not* see my reply_route statements.
one reason can be that TM does not match the reply to any transaction.
Can you paste here the INVITE and the reply with problems? Will help
to troubleshoot even there is another reason.
Ok, Here is my log.
Thank you for your time !
* Logs with RECEIVED are the one from mn_received() method
* Logs with REPLY are the one from module response callback.
* in brackets : callid, From -> To and ip source -> ip dest]
* Then headers, printed from openser sip_msg struct
T000 12/02/2008 15:07:19.756 bin#ser#05138#-1 = (sermonicom.cc:317) [3084977856]
MONICOM RECEIVED .
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>]
[10.170.72.38/5060 -> 10.170.74.21/5060]
[234895 REQUEST INVITE sip:TO@ccc SIP/2.0]
Via=SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
To=<sip:TO@ccc>
Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
CSeq=31558 INVITE
Contact=<sip:10.170.72.38:5060>
Allow-Events=refer
Max-Forwards=69
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY, SUBSCRIBE, UPDATE
Content-Type: application/sdp
Supported: 100rel, timer, replaces
User-Agent: TELES.MGC
Content-Length: 291
v=0
o=- 1183407772 0 IN IP4 10.170.72.109
s=session
c=IN IP4 10.170.72.109
t=0 0
m=audio 14720 RTP/AVP 8 0 97 2 99 96
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:97 G726-16/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:99 G726-40/8000
a=rtpmap:96 telephone-event/8000
a=sendrecv
..
Serial forking
T000 12/02/2008 15:07:19.757 bin#ser#05138#-1 = (sermonicom.cc:293) [3084977856]
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>]
[10.170.72.38/5060 -> 10.170.74.21/5060]
[234895 REQUEST INVITE sip:TO@ccc SIP/2.0] -- .[openser.cfg.m4:963] route_serial_forking
: Sending 'RUri=sip:TO@ccc ' to first contact 'DUri=sip:TO@10.170.74.24:20555
'.
Incoming response 180 Ringing
T000 12/02/2008 15:07:19.758 bin#ser#05136#-1 = (sermonicom.cc:323) [3084977856]
MONICOM RESPONSE .[ -> ]
[10.170.74.24/20555 -> 10.170.74.21/5060]
[236348 REPLY 180 Ringing SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.0;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=118d620a
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20555>
CSeq: 31558 INVITE
Content-Length: 0
.... is handled in onreply_route. I see it there
T000 12/02/2008 15:07:19.758 bin#ser#05136#-1 = (sermonicom.cc:293) [3084977856] .
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=118d620a]
[10.170.74.24/20555 -> 10.170.74.21/5060]
[236348 REPLY 180 Ringing SIP/2.0] -- .[openser.cfg.m4:677] reply for INVITE.
Incoming response 200 ok
T000 12/02/2008 15:07:19.760 bin#ser#05122#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20555 -> 10.170.74.21/5060]
[235990 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.0;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=118d620a
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20555>
CSeq: 31558 INVITE
Content-Length: 224
Content-Type: application/sdp
v=0
o=- 2127131933 2127131933 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40608 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
**
Log from oneply_route are not printed here for 200 ok.
But there is an incoming ACK so the initial caller received it.
Openser relayed it statelessely ?
**
T000 12/02/2008 15:07:19.762 bin#ser#05125#-1 = (sermonicom.cc:317) [3084977856]
MONICOM RECEIVED .
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=118d620a]
[10.170.72.38/5060 -> 10.170.74.21/5060]
[235385 REQUEST ACK sip:ccc@10.170.74.24:20555 SIP/2.0]
Via=SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F0859FF56AAB0
Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
To=<sip:TO@ccc>;tag=118d620a
Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
CSeq=31558 ACK
Contact=<sip:FROM@10.170.72.38:5060>
Max-Forwards=69
Content-Length: 0
ACK is handled ok
T000 12/02/2008 15:07:19.762 bin#ser#05125#-1 = (sermonicom.cc:293) [3084977856]
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=118d620a]
[10.170.72.38/5060 -> 10.170.74.21/5060]
[235385 REQUEST ACK sip:ccc@10.170.74.24:20555 SIP/2.0] -- .[openser.cfg.m4:637]
Processing ok : t_relay DUri= RUri=sip:ccc@10.170.74.24:20555 .
All goes ok, the conversation ends 30 seconds later
T000 12/02/2008 15:07:49.191 bin#ser#05131#-1 = (sermonicom.cc:317) [3084977856]
MONICOM RECEIVED
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=118d620a]
[10.170.72.38/5060 -> 10.170.74.21/5060]
[235413 REQUEST BYE sip:ccc@10.170.74.24:20555 SIP/2.0]
Via=SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F13D830F0C46B
Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
To=<sip:TO@ccc>;tag=118d620a
Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
CSeq=31559 BYE
Contact=<sip:FROM@10.170.72.38:5060>
Max-Forwards=69
Content-Length: 0
BYE is processed ok
T000 12/02/2008 15:07:49.192 bin#ser#05131#-1 = (sermonicom.cc:293) [3084977856] .
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=118d620a]
[10.170.72.38/5060 -> 10.170.74.21/5060]
[235413 REQUEST BYE sip:ccc@10.170.74.24:20555 SIP/2.0] -- .[openser.cfg.m4:637]
Processing ok : t_relay DUri= RUri=sip:ccc@10.170.74.24:20555
And we got the 200 ok
T000 12/02/2008 15:07:49.193 bin#ser#05122#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20555 -> 10.170.74.21/5060]
[236083 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK724a.ea42f1f3.0;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F13D830F0C46B
To: <sip:TO@ccc>;tag=118d620a
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20555>
CSeq: 31559 BYE
Content-Length: 0
Which is retransmitted ???? ...
T000 12/02/2008 15:07:49.677 bin#ser#05136#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20555 -> 10.170.74.21/5060]
[236430 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK724a.ea42f1f3.0;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F13D830F0C46B
To: <sip:TO@ccc>;tag=118d620a
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20555>
CSeq: 31559 BYE
Content-Length: 0
Then, 1'30 after BYE, which is 2' after initial INVITE : the onfailure route for
serial forking triggers and send INVITE to next contact
T000 12/02/2008 15:09:19.143 bin#ser#05142#-1 = (sermonicom.cc:293) [3084977856]
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>]
[10.170.72.38/5060 -> 10.170.74.21/5060]
[234894 REQUEST INVITE sip:TO@ccc SIP/2.0] -- .[openser.cfg.m4:987] serial fork on
failure : Sending 'RUri= ' to next contact 'DUri=sip:TO@10.170.74.24:20540
'.
Openser sent a cancel to initial contact
Which is no more referenced because of the previous BYE so it leads to 481
T000 12/02/2008 15:09:19.144 bin#ser#05124#-1 = (sermonicom.cc:323) [3084977856]
MONICOM RESPONSE
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>]
[10.170.74.24/20555 -> 10.170.74.21/5060]
[235741 REPLY 481 Call leg/Transaction does not exist SIP/2.0] Via=SIP/2.0/UDP
10.170.74.21;branch=z9hG4bK824a.36ce84a7.0;received=10.170.74.21
To=<sip:TO@ccc>
From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact=<sip:ccc@10.170.74.24:20555>
CSeq=31558 CANCEL
But Second Invite is ok and is processed ok
180 Ringing
T000 12/02/2008 15:09:19.144 bin#ser#05125#-1 = (sermonicom.cc:323) [3084977856]
MONICOM RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[235729 REPLY 180 Ringing SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 0
T000 12/02/2008 15:09:19.144 bin#ser#05125#-1 = (sermonicom.cc:293) [3084977856] .
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=1e27ac08]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[235729 REPLY 180 Ringing SIP/2.0] -- .[openser.cfg.m4:677] reply for INVITE.
200 OK
T000 12/02/2008 15:09:19.153 bin#ser#05134#-1 = (sermonicom.cc:323) [3084977856]
MONICOM RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[237162 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
Which is handled in onreply_route
T000 12/02/2008 15:09:19.153 bin#ser#05134#-1 = (sermonicom.cc:293) [3084977856] .
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=1e27ac08]
[10.170.74.24/20540 -> 10.170.74.21/5060] [237162 REPLY 200 OK SIP/2.0] --
.[openser.cfg.m4:677] reply for INVITE.
But retransmitted (not aced by openser ? or ACK has been lost)
T000 12/02/2008 15:09:19.655 bin#ser#05136#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[236665 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
And retransmitted ...
T000 12/02/2008 15:09:20.655 bin#ser#05125#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[235785 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
And handled ok
T000 12/02/2008 15:09:20.655 bin#ser#05125#-1 = (sermonicom.cc:293) [3084977856]
.[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=1e27ac08] [10.170.74.24/20540 -> 10.170.74.21/5060] [235785
REPLY 200 OK SIP/2.0] -- .[openser.cfg.m4:677] reply for INVITE.
But still retransmitted
T000 12/02/2008 15:09:22.655 bin#ser#05124#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[235788 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
..
And again handled in onreply_route
T000 12/02/2008 15:09:22.655 bin#ser#05124#-1 = (sermonicom.cc:293) [3084977856] .
[Call-ID=001B2105E7ACD49F08589FB6EE44(a)10.170.72.38]
[From=<sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR ->
To=<sip:TO@ccc>;tag=1e27ac08]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[235788 REPLY 200 OK SIP/2.0] -- .[openser.cfg.m4:677] reply for INVITE.
But retransmitted
T000 12/02/2008 15:09:26.655 bin#ser#05134#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[237198 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
Reply_route is not called there
Retransmitted
T000 12/02/2008 15:09:30.654 bin#ser#05124#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[235800 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
No reply route
Retransmitted
T000 12/02/2008 15:09:34.655 bin#ser#05134#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[237215 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
..
And again
T000 12/02/2008 15:09:38.655 bin#ser#05122#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[236425 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
..
And again
T000 12/02/2008 15:09:42.655 bin#ser#05136#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[236733 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
..
And again
T000 12/02/2008 15:09:46.656 bin#ser#05131#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[235778 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
..
And again
T000 12/02/2008 15:09:50.655 bin#ser#05122#-1 = (sermonicom.cc:323) [3084977856] MONICOM
RESPONSE .[ -> ]
[10.170.74.24/20540 -> 10.170.74.21/5060]
[236492 REPLY 200 OK SIP/2.0]
Record-Route=<sip:10.170.74.21;lr=on;ftag=05p50qBVv20004jR0501u00cVFk0YrBzR>
Via=SIP/2.0/UDP 10.170.74.21;branch=z9hG4bK824a.36ce84a7.1;received=10.170.74.21,
SIP/2.0/UDP 10.170.72.38:5060;branch=z9hG4bK001B2105E7ACD49F085841888DF3
To: <sip:TO@ccc>;tag=1e27ac08
From: <sip:FROM@10.170.72.38>;tag=05p50qBVv20004jR0501u00cVFk0YrBzR
Call-ID: 001B2105E7ACD49F08589FB6EE44(a)10.170.72.38
Contact: <sip:ccc@10.170.74.24:20540>
CSeq: 31558 INVITE
Content-Length: 222
Content-Type: application/sdp
v=0
o=- 621324986 621324986 IN IP4 10.170.74.24
s=Session SDP
c=IN IP4 10.170.74.24
t=0 0
m=audio 40136 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
..
Cheers,
Daniel
- A sends ACK for INVITE
- ACK is relayed to B
2 minutes later (fr_inv_timer), the failure_route[INVITE] is triggered !
Since I use failure routes to manage serial forking, this means
openser forward the initial INVITE to the other destination, though
first call was established !
Moreover, first call, which seems ok is CANCELED by the openser (I
can see a 200 answer to a cancel from B)
Openser did not disarm the fr_inv_timer on "200" answer to INVITE ?
Openser did not triggered my onreply_route...
Has someone already experienced this ?
Has someone a clue where it may come from ?
- Sometimes it works ok
- Sometimes, 180 is not "seen" and 200 is ok
- Sometimes 180 is seen but not 200
- Sometimes neither 180, nor 200 are seen
- Headers in 180 and 200 are the same except for content
- I'm running openser-1.2.0 (ouch !)
I'm stuck !
Could this be related to
2008-05-15 10:59 Bogdan-Andrei Iancu, <bogdan at voice-system dot ro>
* [r4191] modules/tm/t_reply.c:
backport from trunk (rev #4190):
- fixed race condition that may lead to deadlock on the
transaction
lock. As the reply route (t_on_reply()) stored in transaction
may be
changed in reply route br the current process or any other
process, to
avoid race conditions, it is better to make a local copy of the
reply
route number to be sure it will not be changed.
The deadlock can appear as the reply route number is used in
several
conditions to determine id locking is required. But as this
value may
be changed (by current or other process), it may lead to multiple
lockings with no unlock -> deadlock.
NOTE: this might happen only if onreply_avp_mode is turned on.
Aurelien
_______________________________________________
Users mailing list
Users(a)lists.kamailio.org
http://lists.kamailio.org/cgi-bin/mailman/listinfo/users