Re: [Ekiga-list] Prack issue



Hello Ruben,

I think your kamailio config does not handle the PRACK.

Actually, the ACK request and the PRACK requests follow the same routing procedure :
http://www.in2eps.com/fo-sip/tk-fo-sip-dialog.html

The PRACK request should thus be sent to the first route of the dialog, which is the proxy. This is because the proxy forces record routing. If the proxy was not forcing record routing, BYE, ACK and PRACK requests would be routed directly "peer to peer". But that would mean that the proxy would be unaware of those requests. That is why most configurations force record routing.

If you have access to the configuration of your kamailio proxy, just replace is_method("ACK") by is_method("PRACK).

Damien

Le 07/05/14 09:35, Rubén Gracia a écrit :
Hello Damien,
Sorry for the late response (my mail was waiting moderator approval because of the size) and for not sending the logs before (X.X.X.X is the registrar server, Y.Y.Y.Y is the Ekiga1 and Z.Z.Z.Z is the Ekiga2):

2014/05/06 10:57:09.733      2:17.340 Pool:0x7fd24007f700    SIP    Sending PDU (1035 bytes) to: rem=udp$X.X.X.X:5060,local=udp$Y.Y.Y.Y:5060,if=Y.Y.Y.Y%tun0
INVITE sip:100456 X X X X SIP/2.0
CSeq: 2 INVITE
Via: SIP/2.0/UDP Y.Y.Y.Y:5060;branch=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b;rport
User-Agent: Ekiga/4.0.1
From: <sip:100789 X X X X>;tag=d2625313-6ad3-e311-83eb-60eb69ebd33b
Call-ID: 42705313-6ad3-e311-83eb-60eb69ebd33b localhost localdomain
Supported: 100rel,replaces
To: <sip:100456 X X X X>
Contact: <sip:Ruben Y Y Y Y>
Proxy-Authorization: Digest username="100789", realm="X.X.X.X", nonce="U2ilEVNoo+WAXxiyIg7gg4bIzQ2x2qVeQobPtcA=", uri="sip:100456 X X X X", algorithm=MD5, response="e7aa17cbcd046d2970b1b64a823d057f"
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
Content-Length: 252
Content-Type: application/sdp
Max-Forwards: 70

v=0
o=- 1399366629 1 IN IP4 Y.Y.Y.Y
s=Ekiga/4.0.1
c=IN IP4 Y.Y.Y.Y
t=0 0
m=audio 5062 RTP/AVP 0 8 101
a=sendrecv
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x25208f0)
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x25208f0)
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x25208f0)
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    OpalUDP    Setting interface to Y.Y.Y.Y%tun0
2014/05/06 10:57:09.734      2:17.341 Housekeepe...d285998700    PTLib    MONITOR: timers=5, expiries=8
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SIP    Transaction timers set: retry=0.500, completion=1:00.000
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x7fd248010690)
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Increment reference count to 3 for SIPInvite 0x7fd248010690
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Increment reference count to 4 for SIPInvite 0x7fd248010690
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 3 for SIPInvite 0x7fd248010690
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x292a920)
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SIP    INVITE transaction id=z9hG4bK1e6f5513-6ad3-e311-83eb-60eb69ebd33b completed.
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x7fd248008a20)
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 3 for SIPInvite 0x7fd248008a20
2014/05/06 10:57:09.734      2:17.341 Pool:0x7fd24007f700    SIP    Handled PDU "1 INVITE <407>"
2014/05/06 10:57:09.735      2:17.341 Housekeepe...d285998700    PTLib    MONITOR: timers=7, expiries=10
2014/05/06 10:57:09.735      2:17.341 Pool:0x7fd24007f700    PTLib    Destroying read/write mutex 0x7fd260006b30
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    SafeColl    Waiting readWrite (0x25208f0)
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    SafeColl    Locked readWrite (0x25208f0)
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    PTLib    PThread::PXBlockOnIO(34,0)
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    SafeColl    Unlocked readWrite (0x25208f0)
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    PTLib    Created read/write mutex 0x7fd260003ba0
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    SafeColl    Increment reference count to 4 for PMonitoredSocketBundle 0x25208f0
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    OpalUDP    Binding to interface: Y.Y.Y.Y:5060
2014/05/06 10:57:09.999      2:17.606    Opal Liste...d285606700    PTLib    Created read/write mutex 0x7fd260005e30
2014/05/06 10:57:10.000      2:17.606    Opal Liste...d285606700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.000      2:17.606    Opal Liste...d285606700    SIP    Waiting for PDU on udp$X.X.X.X:5060<if=udp$Y.Y.Y.Y:5060>
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SIP    PDU received: rem=udp$X.X.X.X:5060,local=udp$Y.Y.Y.Y:5060,if=Y.Y.Y.Y%tun0
SIP/2.0 100 trying -- your call is important to us
CSeq: 2 INVITE
Via: SIP/2.0/UDP Y.Y.Y.Y:5060;branch=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b;rport=5060
Server: kamailio (4.2.0-dev0 (x86_64/linux))
From: <sip:100789 X X X X>;tag=d2625313-6ad3-e311-83eb-60eb69ebd33b
Call-ID: 42705313-6ad3-e311-83eb-60eb69ebd33b localhost localdomain
To: <sip:100456 X X X X>
Content-Length: 0


2014/05/06 10:57:10.000      2:17.607    Opal Liste...d285606700    SIP    Queueing PDU "2 INVITE <100>", transaction=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b, token=d2625313-6ad3-e311-83eb-60eb69ebd33b
2014/05/06 10:57:10.001      2:17.607    Opal Liste...d285606700    Opal    Transport clean up on termination
2014/05/06 10:57:10.001      2:17.607    Opal Liste...d285606700    Opal    Transport Close
2014/05/06 10:57:10.001      2:17.607 Pool:0x7fd24007f700    SIP    Handling PDU "2 INVITE <100>" for transaction=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b
2014/05/06 10:57:10.001      2:17.608 Pool:0x7fd24007f700    SafeColl    Increment reference count to 4 for SIPInvite 0x7fd248010690
2014/05/06 10:57:10.001      2:17.608    Opal Liste...d285606700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.001      2:17.608    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.001      2:17.608    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.001      2:17.608    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.001      2:17.607    Opal Liste...d285606700    Opal    Deleted transport udp$X.X.X.X:5060<if=udp$Y.Y.Y.Y:5060>
2014/05/06 10:57:10.001      2:17.608    Opal Liste...d285606700    SafeColl    Decrement reference count to 3 for PMonitoredSocketBundle 0x25208f0
2014/05/06 10:57:10.001      2:17.608    Opal Liste...d285606700    PTLib    Destroying read/write mutex 0x7fd260003ba0
2014/05/06 10:57:10.002      2:17.608    Opal Liste...d285606700    SafeColl    Waiting readWrite (0x25208f0)
2014/05/06 10:57:10.002      2:17.608    Opal Liste...d285606700    SafeColl    Locked readWrite (0x25208f0)
2014/05/06 10:57:10.002      2:17.608    Opal Liste...d285606700    SafeColl    Unlocked readWrite (0x25208f0)
2014/05/06 10:57:10.001      2:17.608 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x292a920)
2014/05/06 10:57:10.002      2:17.608 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x292a920)
2014/05/06 10:57:10.002      2:17.608 Pool:0x7fd24007f700    SafeColl    Increment reference count to 4 for SIPInvite 0x7fd248008a20
2014/05/06 10:57:10.002      2:17.609 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 3 for SIPInvite 0x7fd248008a20
2014/05/06 10:57:10.002      2:17.609 Pool:0x7fd24007f700    SafeColl    Increment reference count to 5 for SIPInvite 0x7fd248010690
2014/05/06 10:57:10.002      2:17.609 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 4 for SIPInvite 0x7fd248010690
2014/05/06 10:57:10.002      2:17.609 Pool:0x7fd24007f700    SIP    Route set is
2014/05/06 10:57:10.003      2:17.609 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x2921e00)
2014/05/06 10:57:10.003      2:17.609 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x2921e00)
2014/05/06 10:57:10.003      2:17.609 Pool:0x7fd24007f700    SafeColl    Increment reference count to 3 for OpalPCSSConnection 0x2922600
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Waiting read (0x2922600)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Locked read (0x2922600)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Increment reference count to 5 for SIPConnection 0x292a920
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Waiting read (0x292a920)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Locked read (0x292a920)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x292a920)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 4 for SIPConnection 0x292a920
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x2922600)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 2 for OpalPCSSConnection 0x2922600
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x2921e00)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SIP    Product Info: name="kamailio", version="", vendor="", comments="(4.2.0-dev0 (x86_64/linux))"
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x292a920)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x7fd248010690)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x7fd248010690)
2014/05/06 10:57:10.003      2:17.610 Pool:0x7fd24007f700    SIP    INVITE transaction id=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b proceeding.
2014/05/06 10:57:10.004      2:17.610 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x292a920)
2014/05/06 10:57:10.004      2:17.610 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x292a920)
2014/05/06 10:57:10.004      2:17.610 Housekeepe...d285998700    PTLib    MONITOR: timers=7, expiries=11
2014/05/06 10:57:10.004      2:17.611 Pool:0x7fd24007f700    SIP    Received Trying response
2014/05/06 10:57:10.004      2:17.611 Housekeepe...d285998700    PTLib    MONITOR: timers=7, expiries=13
2014/05/06 10:57:10.004      2:17.611 Pool:0x7fd24007f700    SafeColl    Increment reference count to 4 for SIPSubscribeHandler 0x7fd25c006200
2014/05/06 10:57:10.004      2:17.611 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 3 for SIPSubscribeHandler 0x7fd25c006200
2014/05/06 10:57:10.004      2:17.611 Pool:0x7fd24007f700    SafeColl    Increment reference count to 6 for SIPRegisterHandler 0x7fd2580066a0
2014/05/06 10:57:10.004      2:17.611 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 5 for SIPRegisterHandler 0x7fd2580066a0
2014/05/06 10:57:10.004      2:17.611 Pool:0x7fd24007f700    OpalCon    SetPhase from SetUpPhase to ProceedingPhase for Call[Cef92c41b1]-EP<sip>[d2625313-6ad3-e311-83eb-60eb69ebd33b]
2014/05/06 10:57:10.005      2:17.611 Pool:0x7fd24007f700    OpalMan    OnProceeding Call[Cef92c41b1]-EP<sip>[d2625313-6ad3-e311-83eb-60eb69ebd33b]
2014/05/06 10:57:10.005      2:17.611 Pool:0x7fd24007f700    Call    OnProceeding Call[Cef92c41b1]-EP<sip>[d2625313-6ad3-e311-83eb-60eb69ebd33b]
2014/05/06 10:57:10.005      2:17.611 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x292a920)
2014/05/06 10:57:10.005      2:17.612 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x7fd248010690)
2014/05/06 10:57:10.005      2:17.612 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 3 for SIPInvite 0x7fd248010690
2014/05/06 10:57:10.005      2:17.612 Pool:0x7fd24007f700    SIP    Handled PDU "2 INVITE <100>"
2014/05/06 10:57:10.005      2:17.612 Pool:0x7fd24007f700    PTLib    Destroying read/write mutex 0x7fd260005e30
2014/05/06 10:57:10.067      2:17.674 Housekeepe...d285998700    PTLib    MONITOR: timers=7, expiries=13
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    SafeColl    Waiting readWrite (0x25208f0)
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    SafeColl    Locked readWrite (0x25208f0)
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    PTLib    PThread::PXBlockOnIO(34,0)
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    SafeColl    Unlocked readWrite (0x25208f0)
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    PTLib    Created read/write mutex 0x7fd260003ba0
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    SafeColl    Increment reference count to 4 for PMonitoredSocketBundle 0x25208f0
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.207      2:17.814    Opal Liste...d285606700    OpalUDP    Binding to interface: Y.Y.Y.Y:5060
2014/05/06 10:57:10.208      2:17.814    Opal Liste...d285606700    PTLib    Created read/write mutex 0x7fd260005e30
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.208      2:17.814    Opal Liste...d285606700    SIP    Waiting for PDU on udp$X.X.X.X:5060<if=udp$Y.Y.Y.Y:5060>
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.208      2:17.815    Opal Liste...d285606700    SIP    PDU received: rem=udp$X.X.X.X:5060,local=udp$Y.Y.Y.Y:5060,if=Y.Y.Y.Y%tun0
SIP/2.0 180 Ringing
CSeq: 2 INVITE
Via: SIP/2.0/UDP Y.Y.Y.Y:5060;branch=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b;rport=5060
User-Agent: Ekiga/3.3.2
From: <sip:100789 X X X X>;tag=d2625313-6ad3-e311-83eb-60eb69ebd33b
Call-ID: 42705313-6ad3-e311-83eb-60eb69ebd33b localhost localdomain
To: <sip:100456 X X X X>;tag=08398313-6ad3-e311-88db-74de2bedfc3c
Contact: <sip:100456 Z Z Z Z:5060>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
RSeq: 545639205
Require: 100rel
Content-Length: 0
Record-Route: <sip:X.X.X.X;lr=on>


2014/05/06 10:57:10.209      2:17.816    Opal Liste...d285606700    SIP    Queueing PDU "2 INVITE <180>", transaction=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b, token=d2625313-6ad3-e311-83eb-60eb69ebd33b
2014/05/06 10:57:10.209      2:17.816    Opal Liste...d285606700    Opal    Transport clean up on termination
2014/05/06 10:57:10.209      2:17.816 Pool:0x7fd24007f700    SIP    Handling PDU "2 INVITE <180>" for transaction=z9hG4bK32966f13-6ad3-e311-83eb-60eb69ebd33b
2014/05/06 10:57:10.209      2:17.816 Pool:0x7fd24007f700    SafeColl    Increment reference count to 4 for SIPInvite 0x7fd248010690
2014/05/06 10:57:10.209      2:17.816    Opal Liste...d285606700    Opal    Transport Close
2014/05/06 10:57:10.209      2:17.816 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x292a920)
2014/05/06 10:57:10.209      2:17.816    Opal Liste...d285606700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.209      2:17.816 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x292a920)
2014/05/06 10:57:10.210      2:17.816    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.210      2:17.817    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.210      2:17.817 Pool:0x7fd24007f700    SafeColl    Increment reference count to 4 for SIPInvite 0x7fd248008a20
2014/05/06 10:57:10.210      2:17.817    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.209      2:17.816    Opal Liste...d285606700    Opal    Deleted transport udp$X.X.X.X:5060<if=udp$Y.Y.Y.Y:5060>
2014/05/06 10:57:10.210      2:17.817 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 3 for SIPInvite 0x7fd248008a20
2014/05/06 10:57:10.210      2:17.817 Pool:0x7fd24007f700    SafeColl    Increment reference count to 5 for SIPInvite 0x7fd248010690
2014/05/06 10:57:10.210      2:17.817    Opal Liste...d285606700    SafeColl    Decrement reference count to 3 for PMonitoredSocketBundle 0x25208f0
2014/05/06 10:57:10.210      2:17.817 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 4 for SIPInvite 0x7fd248010690
2014/05/06 10:57:10.211      2:17.817    Opal Liste...d285606700    PTLib    Destroying read/write mutex 0x7fd260003ba0
2014/05/06 10:57:10.211      2:17.817    Opal Liste...d285606700    SafeColl    Waiting readWrite (0x25208f0)
2014/05/06 10:57:10.211      2:17.818    Opal Liste...d285606700    SafeColl    Locked readWrite (0x25208f0)
2014/05/06 10:57:10.211      2:17.818    Opal Liste...d285606700    SafeColl    Unlocked readWrite (0x25208f0)
2014/05/06 10:57:10.211      2:17.818 Pool:0x7fd24007f700    SIP    Route set is <sip:X.X.X.X;lr=on>
2014/05/06 10:57:10.211      2:17.818 Pool:0x7fd24007f700    SIP    Updating dialog tag from "" to "08398313-6ad3-e311-88db-74de2bedfc3c"
2014/05/06 10:57:10.212      2:17.818 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x2921e00)
2014/05/06 10:57:10.212      2:17.818 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x2921e00)
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Increment reference count to 3 for OpalPCSSConnection 0x2922600
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Waiting read (0x2922600)
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Locked read (0x2922600)
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Increment reference count to 5 for SIPConnection 0x292a920
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Waiting read (0x292a920)
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Locked read (0x292a920)
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x292a920)
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 4 for SIPConnection 0x292a920
2014/05/06 10:57:10.212      2:17.819 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x2922600)
2014/05/06 10:57:10.213      2:17.819 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 2 for OpalPCSSConnection 0x2922600
2014/05/06 10:57:10.213      2:17.819 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x2921e00)
2014/05/06 10:57:10.213      2:17.819 Pool:0x7fd24007f700    SIP    Product Info: name="Ekiga", version="3.3.2", vendor="", comments=""
2014/05/06 10:57:10.213      2:17.820 Pool:0x7fd24007f700    OpalUDP    Setting interface to Y.Y.Y.Y%tun0
2014/05/06 10:57:10.213      2:17.820 Pool:0x7fd24007f700    PTLib    Created read/write mutex 0x7fd248015620
2014/05/06 10:57:10.213      2:17.820 Pool:0x7fd24007f700    SafeColl    Increment reference count to 5 for SIPConnection 0x292a920
2014/05/06 10:57:10.213      2:17.820 Pool:0x7fd24007f700    SIP    Remote dialog address from route set: sip:X.X.X.X;lr=on
2014/05/06 10:57:10.213      2:17.820 Pool:0x7fd24007f700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.214      2:17.820 Pool:0x7fd24007f700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.214      2:17.820 Pool:0x7fd24007f700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.214      2:17.820 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.214      2:17.821 Pool:0x7fd24007f700    SafeColl    Increment reference count to 6 for SIPRegisterHandler 0x7fd2580066a0
2014/05/06 10:57:10.214      2:17.821 Pool:0x7fd24007f700    SafeColl    Waiting read (0x7fd2580066a0)
2014/05/06 10:57:10.215      2:17.821 Pool:0x7fd24007f700    SafeColl    Locked read (0x7fd2580066a0)
2014/05/06 10:57:10.215      2:17.821 Pool:0x7fd24007f700    SafeColl    Increment reference count to 7 for SIPRegisterHandler 0x7fd2580066a0
2014/05/06 10:57:10.215      2:17.821 Pool:0x7fd24007f700    SafeColl    Waiting read (0x7fd2580066a0)
2014/05/06 10:57:10.215      2:17.822 Pool:0x7fd24007f700    SafeColl    Locked read (0x7fd2580066a0)
2014/05/06 10:57:10.215      2:17.822 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x7fd2580066a0)
2014/05/06 10:57:10.215      2:17.822 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 6 for SIPRegisterHandler 0x7fd2580066a0
2014/05/06 10:57:10.215      2:17.822 Pool:0x7fd24007f700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.215      2:17.822 Pool:0x7fd24007f700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.215      2:17.822 Pool:0x7fd24007f700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.216      2:17.822 Pool:0x7fd24007f700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.216      2:17.822 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x7fd2580066a0)
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 5 for SIPRegisterHandler 0x7fd2580066a0
2014/05/06 10:57:10.216      2:17.823 Pool:0x7fd24007f700    SIP    PRACK transaction id=z9hG4bKca2cb913-6ad3-e311-83eb-60eb69ebd33b created.
2014/05/06 10:57:10.217      2:17.823 Pool:0x7fd24007f700    SafeColl    Increment reference count to 1 for SIPPrack 0x7fd2480155e0
2014/05/06 10:57:10.217      2:17.823 Pool:0x7fd24007f700    SafeColl    Increment reference count to 2 for SIPPrack 0x7fd2480155e0
2014/05/06 10:57:10.217      2:17.823 Pool:0x7fd24007f700    SafeColl    Increment reference count to 3 for SIPPrack 0x7fd2480155e0
2014/05/06 10:57:10.217      2:17.823 Pool:0x7fd24007f700    SafeColl    Decrement reference count to 2 for SIPPrack 0x7fd2480155e0
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    HTTP    Adding authentication information
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x7fd2480155e0)
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x7fd2480155e0)
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    SIP    Transaction remembering interface "Y.Y.Y.Y%tun0"
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    SIP    Transaction remote address is udp$X.X.X.X:5060
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.218      2:17.824 Pool:0x7fd24007f700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.217      2:17.824 Pool:0x7fd24007f700    SIP    Sending PDU (736 bytes) to: rem=udp$X.X.X.X:5060,local=udp$Y.Y.Y.Y:5060,if=Y.Y.Y.Y%tun0
PRACK sip:100456 X X X X SIP/2.0
Route: <sip:X.X.X.X;lr=on>
CSeq: 3 PRACK
Via: SIP/2.0/UDP Y.Y.Y.Y:5060;branch=z9hG4bKca2cb913-6ad3-e311-83eb-60eb69ebd33b;rport
User-Agent: Ekiga/4.0.1
From: <sip:100789 X X X X>;tag=d2625313-6ad3-e311-83eb-60eb69ebd33b
Call-ID: 42705313-6ad3-e311-83eb-60eb69ebd33b localhost localdomain
To: <sip:100456 X X X X>;tag=08398313-6ad3-e311-88db-74de2bedfc3c
RAck: 545639205 2 INVITE
Contact: <sip:Ruben Y Y Y Y>
Proxy-Authorization: Digest username="100789", realm="X.X.X.X", nonce="U2ilEVNoo+WAXxiyIg7gg4bIzQ2x2qVeQobPtcA=", uri="sip:100456 X X X X", algorithm=MD5, response="033c46cb2401d2abaa8d7d244e16583d"
Content-Length: 0
Max-Forwards: 70


2014/05/06 10:57:10.218      2:17.825 Pool:0x7fd24007f700    SafeColl    Waiting readWrite (0x25208f0)
2014/05/06 10:57:10.218      2:17.825 Pool:0x7fd24007f700    SafeColl    Locked readWrite (0x25208f0)
2014/05/06 10:57:10.218      2:17.825 Pool:0x7fd24007f700    SafeColl    Unlocked readWrite (0x25208f0)
2014/05/06 10:57:10.218      2:17.825 Pool:0x7fd24007f700    OpalUDP    Setting interface to Y.Y.Y.Y%tun0
.......
2014/05/06 10:57:10.378      2:17.984    Opal Liste...d285606700    PWLib    Closing channel, fd=56
2014/05/06 10:57:10.378      2:17.984    Opal Liste...d285606700    SafeColl    Waiting read (0x25208f0)
2014/05/06 10:57:10.378      2:17.985    Opal Liste...d285606700    SafeColl    Locked read (0x25208f0)
2014/05/06 10:57:10.378      2:17.985    Opal Liste...d285606700    SafeColl    Unlocked read (0x25208f0)
2014/05/06 10:57:10.378      2:17.984    Opal Liste...d285606700    SIP    PDU received: rem=udp$X.X.X.X:5060,local=udp$Y.Y.Y.Y:5060,if=Y.Y.Y.Y%tun0
SIP/2.0 404 Not here
CSeq: 3 PRACK
Via: SIP/2.0/UDP Y.Y.Y.Y:5060;branch=z9hG4bKca2cb913-6ad3-e311-83eb-60eb69ebd33b;rport=5060
Server: kamailio (4.2.0-dev0 (x86_64/linux))
From: <sip:100789 X X X X>;tag=d2625313-6ad3-e311-83eb-60eb69ebd33b
Call-ID: 42705313-6ad3-e311-83eb-60eb69ebd33b localhost localdomain
To: <sip:100456 X X X X>;tag=08398313-6ad3-e311-88db-74de2bedfc3c
Content-Length: 0


2014/05/06 10:57:10.378      2:17.985    Opal Liste...d285606700    SIP    Queueing PDU "3 PRACK <404>", transaction=z9hG4bKca2cb913-6ad3-e311-83eb-60eb69ebd33b, token=d2625313-6ad3-e311-83eb-60eb69ebd33b
2014/05/06 10:57:10.378      2:17.985    Opal Liste...d285606700    Opal    Transport clean up on termination
2014/05/06 10:57:10.378      2:17.985    Opal Liste...d285606700    Opal    Transport Close
........

2014/05/06 10:57:26.237      2:33.844 Housekeepe...d285998700    SIP    Sending PDU (716 bytes) to: rem=udp$X.X.X.X:5060,local=udp$Y.Y.Y.Y:5060,if=Y.Y.Y.Y%tun0
BYE sip:100456 Z Z Z Z:5060 SIP/2.0
Route: <sip:X.X.X.X;lr=on>
CSeq: 4 BYE
Via: SIP/2.0/UDP Y.Y.Y.Y:5060;branch=z9hG4bK683e2f1b-6ad3-e311-83eb-60eb69ebd33b;rport
User-Agent: Ekiga/4.0.1
From: <sip:100789 X X X X>;tag=d2625313-6ad3-e311-83eb-60eb69ebd33b
Call-ID: 42705313-6ad3-e311-83eb-60eb69ebd33b localhost localdomain
To: <sip:100456 X X X X>;tag=08398313-6ad3-e311-88db-74de2bedfc3c
Contact: <sip:Ruben Y Y Y Y>
Proxy-Authorization: Digest username="100789", realm="X.X.X.X", nonce="U2ilEVNoo+WAXxiyIg7gg4bIzQ2x2qVeQobPtcA=", uri="sip:100456 Z Z Z Z:5060", algorithm=MD5, response="9b6524cf368be46dfe4934bf33d00be8"
Content-Length: 0
Max-Forwards: 70
........

You can see that the contact field received in the ringing message is Z.Z.Z.Z (Ekiga2 ip):

Contact: <sip:100456 Z Z Z Z:5060>
Record-Route: <sip:X.X.X.X;lr=on>

but the prack message is sent to X.X.X.X (registrar server) with Request-URI X.X.X.X instead the Z.Z.Z.Z ip. Because of this, the registrar server doesn't "know" where to route the message. (In fact, it send the prack message to itself). (The BYE  message seems to be ok)

Please let us know anything

Thanks for your time and regards,
_______________________________________________
ekiga-list mailing list
ekiga-list gnome org
https://mail.gnome.org/mailman/listinfo/ekiga-list




Damien SANDRAS

Ekiga Project
http://www.ekiga.org


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]