Initial Register Repeating Twice
Brought to you by:
krunalhire
Menu
▾
▴
#300 Initial Register Repeating Twice
Fixed
nobody
None
Medium
Defect
2010-10-31
2010-10-23
Anonymous
No
Originally created by: jac...@gmail.com
What steps will reproduce the problem?
1. Set up an account with Sipsorcery.
What is the expected output? What do you see instead?
The account shows registered in CSipSimple but it shows unregistered in Sipsorcery.
This only happens with the initial registration. Subsequent registration renewals work fine and Sipsorcery will show the account as registered.
The SIP trace shows that CSipSimple repeats the Register process twice during the initial registration. The immediate second Register process is probably the cause that deregisters the first registration. However, Sipsorcery does OK the immediate second Register, but for some reason, it deregisters the client.
Subsequent registration renewals only do the Register process once for each renewal. So the account registers fine in subsequent registrations.
Test was done with CSipSimple version 0.00-15.
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: r3gis...@gmail.com
CSipSimple relies on pjsip sip stack.
Pjsip guys implemented something cool to solve NAT + port changes without STUN. However it implies that the app register a first time and then deduce from the registration result a correct public IP and re-register.
That's why you see two 2 registrations.
However, should be fine with the server : it first register, then unregister and then register again... unless the sip server doesn't behaves as it should regarding registrations it should register the last registration (all the more so as if you get the registration icon, it means that registration is acknoledge our last registration).
What you could try is to activate STUN (in settings > media > Enable STUN).
Not sure that it will solve the problem since it could still re-register if port change is needed, but it can help.
Status: Invalid
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: jac...@gmail.com
Yes, the duplicate registrations should work fine because Sipsorcery OK'ed the second registration. I posted the issue on Sipsorcery forum before I posted here just in case.
However, you described the process as register, unregister, register. While from the SIP trace，I did not notice the unregister process. More specifically, it was like this:
Register(expires 300), Unauthorized, Register(expires 300), OK, Register(expires 300), Unauthorized, Register(expires 300), OK.
The STUN option does not seem to affect the behavior and result of Register.
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: jac...@gmail.com
Aaron @Sipsorcery has identified the bug. The second Register process sends the registration with "expires=0" in the Contact header which overrules the "Expires" header, and that effectively unregisters the client. But there isn't a third Register process to register the client again until it is the time for the next registration renewal.
Please take a look of the following thread,
http://forum.sipsorcery.com/viewtopic.php?f=6&t=2897&p=17305
Now the question is, the third Register process is missing, is it missing from CSipSimple or for some reason Sipsorcery does not receive it?
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: r3gis...@gmail.com
Indeed at the end of the traces you sent csipsimple should send a last updated register.
Could you try to produce logs in csipsimple?
See how to collect logs wiki page.
With these logs we'll see the device point of view.
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: jac...@gmail.com
The log shows the third Register was not sent out. See the last line stating the registration was successful. It follows immediately after the second Register (expires=0).
======Log===============================
10-24 02:38:04.441 D/libpjsip(28477): 02:38:04.450 pjsua_acc.c Account xxxxxxxx <sip:xxxxxxxx@sipsorcery.com> added with id 0
10-24 02:38:04.451 V/libpjsip(28477): 02:38:04.451 endpoint Request msg REGISTER/cseq=25098 (tdta0x81fec0) created.
10-24 02:38:04.451 V/libpjsip(28477): 02:38:04.451 tsx0x611c0c Transaction created for Request msg REGISTER/cseq=25099 (tdta0x81fec0)
10-24 02:38:04.451 V/libpjsip(28477): 02:38:04.452 tsx0x611c0c Sending Request msg REGISTER/cseq=25099 (tdta0x81fec0) in state Null
10-24 02:38:04.451 V/libpjsip(28477): 02:38:04.452 sip_resolve.c DNS resolver not available, target 'sipsorcery.com:0' type=TCP will be resolved with getaddrinfo()
10-24 02:38:04.741 V/libpjsip(28477): 02:38:04.746 sip_resolve.c Target 'sipsorcery.com:0' type=TCP resolved to '69.59.142.213:5060' type=TCP (TCP transport)
10-24 02:38:04.741 D/libpjsip(28477): 02:38:04.746 pjsua_core.c TX 604 bytes Request msg REGISTER/cseq=25099 (tdta0x81fec0) to tcp 69.59.142.213:5060:
10-24 02:38:04.741 D/libpjsip(28477): REGISTER sip:sipsorcery.com;transport=tcp SIP/2.0
10-24 02:38:04.741 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport;branch=z9hG4bKPjY0POr-9pxT1kDv7C3EbtE3iK4KoKpeCv
10-24 02:38:04.741 D/libpjsip(28477): Max-Forwards: 70
10-24 02:38:04.741 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=VIsRKR9MUVBqDkZCIa7VtzRTwidc8YdF
10-24 02:38:04.741 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>
10-24 02:38:04.741 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:04.741 D/libpjsip(28477): CSeq: 25099 REGISTER
10-24 02:38:04.741 D/libpjsip(28477): User-Agent: CSipSimple
10-24 02:38:04.741 D/libpjsip(28477): Contact: "xxxxxxxx" <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>
10-24 02:38:04.741 D/libpjsip(28477): Expires: 3600
10-24 02:38:04.741 D/libpjsip(28477): Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
10-24 02:38:04.741 D/libpjsip(28477): Content-Length: 0
10-24 02:38:04.741 D/libpjsip(28477):
10-24 02:38:04.741 D/libpjsip(28477):
10-24 02:38:04.741 D/libpjsip(28477): --end msg--
10-24 02:38:04.741 V/libpjsip(28477): 02:38:04.747 tsx0x611c0c State changed from Null to Calling, event=TX_MSG
10-24 02:38:04.741 I/libpjsip(28477): 02:38:04.748 pjsua_acc.c Registration sent
10-24 02:38:04.751 D/Dialer (28477): Update chooser choice
10-24 02:38:04.841 D/SIP AccountList(28477): > Need to update list !
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.258 sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=25099 (rdata0x46c3e4)
10-24 02:38:05.253 D/libpjsip(28477): 02:38:05.258 pjsua_core.c RX 543 bytes Response msg 401/REGISTER/cseq=25099 (rdata0x46c3e4) from tcp 69.59.142.213:5060:
10-24 02:38:05.253 D/libpjsip(28477): SIP/2.0 401 Unauthorised
10-24 02:38:05.253 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport=43602;branch=z9hG4bKPjY0POr-9pxT1kDv7C3EbtE3iK4KoKpeCv;received=xx.xx.xx.xx
10-24 02:38:05.253 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>
10-24 02:38:05.253 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=VIsRKR9MUVBqDkZCIa7VtzRTwidc8YdF
10-24 02:38:05.253 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:05.253 D/libpjsip(28477): CSeq: 25099 REGISTER
10-24 02:38:05.253 D/libpjsip(28477): WWW-Authenticate: Digest realm="sipsorcery.com",nonce="20307226251063734110"
10-24 02:38:05.253 D/libpjsip(28477): Content-Length: 0
10-24 02:38:05.253 D/libpjsip(28477): Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, SUBSCRIBE
10-24 02:38:05.253 D/libpjsip(28477):
10-24 02:38:05.253 D/libpjsip(28477):
10-24 02:38:05.253 D/libpjsip(28477): --end msg--
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.258 tsx0x611c0c Incoming Response msg 401/REGISTER/cseq=25099 (rdata0x46c3e4) in state Calling
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.259 tsx0x611c0c State changed from Calling to Completed, event=RX_MSG
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.259 tsx0x5780fc Transaction created for Request msg REGISTER/cseq=25100 (tdta0x81fec0)
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.259 tsx0x5780fc Sending Request msg REGISTER/cseq=25100 (tdta0x81fec0) in state Null
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.259 endpoint Request msg REGISTER/cseq=25100 (tdta0x81fec0): skipping target resolution because address is already set
10-24 02:38:05.253 D/libpjsip(28477): 02:38:05.259 pjsua_core.c TX 791 bytes Request msg REGISTER/cseq=25100 (tdta0x81fec0) to tcp 69.59.142.213:5060:
10-24 02:38:05.253 D/libpjsip(28477): REGISTER sip:sipsorcery.com;transport=tcp SIP/2.0
10-24 02:38:05.253 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport;branch=z9hG4bKPj5O3yPrxEPZF0qB-9VVjugVPV2Url0BtK
10-24 02:38:05.253 D/libpjsip(28477): Max-Forwards: 70
10-24 02:38:05.253 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=VIsRKR9MUVBqDkZCIa7VtzRTwidc8YdF
10-24 02:38:05.253 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>
10-24 02:38:05.253 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:05.253 D/libpjsip(28477): CSeq: 25100 REGISTER
10-24 02:38:05.253 D/libpjsip(28477): User-Agent: CSipSimple
10-24 02:38:05.253 D/libpjsip(28477): Contact: "xxxxxxxx" <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>
10-24 02:38:05.253 D/libpjsip(28477): Expires: 3600
10-24 02:38:05.253 D/libpjsip(28477): Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
10-24 02:38:05.253 D/libpjsip(28477): Authorization: Digest username="xxxxxxxx", realm="sipsorcery.com", nonce="20307226251063734110", uri="sip:sipsorcery.com;transport=tcp", response="85aaa1f9816081b173dc12dc29261520"
10-24 02:38:05.253 D/libpjsip(28477): Content-Length: 0
10-24 02:38:05.253 D/libpjsip(28477):
10-24 02:38:05.253 D/libpjsip(28477):
10-24 02:38:05.253 D/libpjsip(28477): --end msg--
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.260 tsx0x5780fc State changed from Null to Calling, event=TX_MSG
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.260 tsx0x611c0c Timeout timer event
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.260 tsx0x611c0c State changed from Completed to Terminated, event=TIMER
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.260 tsx0x611c0c Timeout timer event
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.260 tsx0x611c0c State changed from Terminated to Destroyed, event=TIMER
10-24 02:38:05.253 V/libpjsip(28477): 02:38:05.260 tsx0x611c0c Transaction destroyed!
10-24 02:38:05.461 V/libpjsip(28477): 02:38:05.464 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=25100 (rdata0x46c3e4)
10-24 02:38:05.461 D/libpjsip(28477): 02:38:05.464 pjsua_core.c RX 527 bytes Response msg 200/REGISTER/cseq=25100 (rdata0x46c3e4) from tcp 69.59.142.213:5060:
10-24 02:38:05.461 D/libpjsip(28477): SIP/2.0 200 Ok
10-24 02:38:05.461 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport=43602;branch=z9hG4bKPj5O3yPrxEPZF0qB-9VVjugVPV2Url0BtK;received=xx.xx.xx.xx
10-24 02:38:05.461 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=1222246502
10-24 02:38:05.461 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=VIsRKR9MUVBqDkZCIa7VtzRTwidc8YdF
10-24 02:38:05.461 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:05.461 D/libpjsip(28477): CSeq: 25100 REGISTER
10-24 02:38:05.461 D/libpjsip(28477): Contact: <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>;expires=3600
10-24 02:38:05.461 D/libpjsip(28477): Date: Sun, 24 Oct 2010 06:37:51 GMT
10-24 02:38:05.461 D/libpjsip(28477): Content-Length: 0
10-24 02:38:05.461 D/libpjsip(28477): Server: www.sipsorcery.com
10-24 02:38:05.461 D/libpjsip(28477):
10-24 02:38:05.461 D/libpjsip(28477):
10-24 02:38:05.461 D/libpjsip(28477): --end msg--
10-24 02:38:05.461 V/libpjsip(28477): 02:38:05.465 tsx0x5780fc Incoming Response msg 200/REGISTER/cseq=25100 (rdata0x46c3e4) in state Calling
10-24 02:38:05.461 V/libpjsip(28477): 02:38:05.465 tsx0x5780fc State changed from Calling to Completed, event=RX_MSG
10-24 02:38:05.461 I/libpjsip(28477): 02:38:05.465 pjsua_acc.c IP address change detected for account 0 (192.168.1.131:5060 --> xx.xx.xx.xx:43602). Updating registration (using method 2)
10-24 02:38:05.461 V/libpjsip(28477): 02:38:05.466 endpoint Request msg REGISTER/cseq=25100 (tdta0x4b24f0) created.
10-24 02:38:05.461 V/libpjsip(28477): 02:38:05.466 tsx0x45dda4 Transaction created for Request msg REGISTER/cseq=25101 (tdta0x4b24f0)
10-24 02:38:05.461 V/libpjsip(28477): 02:38:05.467 tsx0x45dda4 Sending Request msg REGISTER/cseq=25101 (tdta0x4b24f0) in state Null
10-24 02:38:05.461 V/libpjsip(28477): 02:38:05.467 sip_resolve.c DNS resolver not available, target 'sipsorcery.com:0' type=TCP will be resolved with getaddrinfo()
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.754 sip_resolve.c Target 'sipsorcery.com:0' type=TCP resolved to '69.59.142.213:5060' type=TCP (TCP transport)
10-24 02:38:05.751 D/libpjsip(28477): 02:38:05.754 pjsua_core.c TX 678 bytes Request msg REGISTER/cseq=25101 (tdta0x4b24f0) to tcp 69.59.142.213:5060:
10-24 02:38:05.751 D/libpjsip(28477): REGISTER sip:sipsorcery.com;transport=tcp SIP/2.0
10-24 02:38:05.751 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport;branch=z9hG4bKPjqPc4b.6TQm.Wf1cOwW63B4Nd9fVUhXd8
10-24 02:38:05.751 D/libpjsip(28477): Max-Forwards: 70
10-24 02:38:05.751 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=B40XJxsmT1weNpHkCqHLWyd2qLMNFqz1
10-24 02:38:05.751 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>
10-24 02:38:05.751 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:05.751 D/libpjsip(28477): CSeq: 25101 REGISTER
10-24 02:38:05.751 D/libpjsip(28477): User-Agent: CSipSimple
10-24 02:38:05.751 D/libpjsip(28477): Contact: <sip:xxxxxxxx@xx.xx.xx.xx:43602;transport=tcp>
10-24 02:38:05.751 D/libpjsip(28477): Contact: "xxxxxxxx" <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>;expires=0
10-24 02:38:05.751 D/libpjsip(28477): Expires: 3600
10-24 02:38:05.751 D/libpjsip(28477): Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
10-24 02:38:05.751 D/libpjsip(28477): Content-Length: 0
10-24 02:38:05.751 D/libpjsip(28477):
10-24 02:38:05.751 D/libpjsip(28477):
10-24 02:38:05.751 D/libpjsip(28477): --end msg--
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.755 tsx0x45dda4 State changed from Null to Calling, event=TX_MSG
10-24 02:38:05.751 I/libpjsip(28477): 02:38:05.755 pjsua_acc.c Registration sent
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.756 tsx0x5780fc Timeout timer event
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.756 tsx0x5780fc State changed from Completed to Terminated, event=TIMER
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.756 tsx0x5780fc Timeout timer event
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.756 tsx0x5780fc State changed from Terminated to Destroyed, event=TIMER
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.756 tdta0x81fec0 Destroying txdata Request msg REGISTER/cseq=25100 (tdta0x81fec0)
10-24 02:38:05.751 V/libpjsip(28477): 02:38:05.756 tsx0x5780fc Transaction destroyed!
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.977 sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=25101 (rdata0x46c3e4)
10-24 02:38:05.972 D/libpjsip(28477): 02:38:05.977 pjsua_core.c RX 543 bytes Response msg 401/REGISTER/cseq=25101 (rdata0x46c3e4) from tcp 69.59.142.213:5060:
10-24 02:38:05.972 D/libpjsip(28477): SIP/2.0 401 Unauthorised
10-24 02:38:05.972 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport=43602;branch=z9hG4bKPjqPc4b.6TQm.Wf1cOwW63B4Nd9fVUhXd8;received=xx.xx.xx.xx
10-24 02:38:05.972 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>
10-24 02:38:05.972 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=B40XJxsmT1weNpHkCqHLWyd2qLMNFqz1
10-24 02:38:05.972 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:05.972 D/libpjsip(28477): CSeq: 25101 REGISTER
10-24 02:38:05.972 D/libpjsip(28477): WWW-Authenticate: Digest realm="sipsorcery.com",nonce="20307226251648140053"
10-24 02:38:05.972 D/libpjsip(28477): Content-Length: 0
10-24 02:38:05.972 D/libpjsip(28477): Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, REGISTER, SUBSCRIBE
10-24 02:38:05.972 D/libpjsip(28477):
10-24 02:38:05.972 D/libpjsip(28477):
10-24 02:38:05.972 D/libpjsip(28477): --end msg--
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.977 tsx0x45dda4 Incoming Response msg 401/REGISTER/cseq=25101 (rdata0x46c3e4) in state Calling
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.977 tsx0x45dda4 State changed from Calling to Completed, event=RX_MSG
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.977 tsx0x674c8c Transaction created for Request msg REGISTER/cseq=25102 (tdta0x4b24f0)
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.977 tsx0x674c8c Sending Request msg REGISTER/cseq=25102 (tdta0x4b24f0) in state Null
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.978 endpoint Request msg REGISTER/cseq=25102 (tdta0x4b24f0): skipping target resolution because address is already set
10-24 02:38:05.972 D/libpjsip(28477): 02:38:05.978 pjsua_core.c TX 865 bytes Request msg REGISTER/cseq=25102 (tdta0x4b24f0) to tcp 69.59.142.213:5060:
10-24 02:38:05.972 D/libpjsip(28477): REGISTER sip:sipsorcery.com;transport=tcp SIP/2.0
10-24 02:38:05.972 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport;branch=z9hG4bKPji7itted.oxGtE9TjBJwT96Kb.a-jLGCt
10-24 02:38:05.972 D/libpjsip(28477): Max-Forwards: 70
10-24 02:38:05.972 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=B40XJxsmT1weNpHkCqHLWyd2qLMNFqz1
10-24 02:38:05.972 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>
10-24 02:38:05.972 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:05.972 D/libpjsip(28477): CSeq: 25102 REGISTER
10-24 02:38:05.972 D/libpjsip(28477): User-Agent: CSipSimple
10-24 02:38:05.972 D/libpjsip(28477): Contact: <sip:xxxxxxxx@xx.xx.xx.xx:43602;transport=tcp>
10-24 02:38:05.972 D/libpjsip(28477): Contact: "xxxxxxxx" <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>;expires=0
10-24 02:38:05.972 D/libpjsip(28477): Expires: 3600
10-24 02:38:05.972 D/libpjsip(28477): Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
10-24 02:38:05.972 D/libpjsip(28477): Authorization: Digest username="xxxxxxxx", realm="sipsorcery.com", nonce="20307226251648140053", uri="sip:sipsorcery.com;transport=tcp", response="426dd268e71cc9a08b554396ada594dc"
10-24 02:38:05.972 D/libpjsip(28477): Content-Length: 0
10-24 02:38:05.972 D/libpjsip(28477):
10-24 02:38:05.972 D/libpjsip(28477):
10-24 02:38:05.972 D/libpjsip(28477): --end msg--
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.979 tsx0x674c8c State changed from Null to Calling, event=TX_MSG
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.979 tsx0x45dda4 Timeout timer event
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.979 tsx0x45dda4 State changed from Completed to Terminated, event=TIMER
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.979 tsx0x45dda4 Timeout timer event
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.979 tsx0x45dda4 State changed from Terminated to Destroyed, event=TIMER
10-24 02:38:05.972 V/libpjsip(28477): 02:38:05.979 tsx0x45dda4 Transaction destroyed!
10-24 02:38:06.181 V/libpjsip(28477): 02:38:06.183 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=25102 (rdata0x46c3e4)
10-24 02:38:06.181 D/libpjsip(28477): 02:38:06.184 pjsua_core.c RX 451 bytes Response msg 200/REGISTER/cseq=25102 (rdata0x46c3e4) from tcp 69.59.142.213:5060:
10-24 02:38:06.181 D/libpjsip(28477): SIP/2.0 200 Ok
10-24 02:38:06.181 D/libpjsip(28477): Via: SIP/2.0/TCP xx.xx.xx.xx:43602;rport=43602;branch=z9hG4bKPji7itted.oxGtE9TjBJwT96Kb.a-jLGCt;received=xx.xx.xx.xx
10-24 02:38:06.181 D/libpjsip(28477): To: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=1719811563
10-24 02:38:06.181 D/libpjsip(28477): From: "xxxxxxxx" <sip:xxxxxxxx@sipsorcery.com>;tag=B40XJxsmT1weNpHkCqHLWyd2qLMNFqz1
10-24 02:38:06.181 D/libpjsip(28477): Call-ID: QDGulhRgvkOfmTiQqsLUjbWeaZ.Ms9Qx
10-24 02:38:06.181 D/libpjsip(28477): CSeq: 25102 REGISTER
10-24 02:38:06.181 D/libpjsip(28477): Date: Sun, 24 Oct 2010 06:37:51 GMT
10-24 02:38:06.181 D/libpjsip(28477): Content-Length: 0
10-24 02:38:06.181 D/libpjsip(28477): Server: www.sipsorcery.com
10-24 02:38:06.181 D/libpjsip(28477):
10-24 02:38:06.181 D/libpjsip(28477):
10-24 02:38:06.181 D/libpjsip(28477): --end msg--
10-24 02:38:06.181 V/libpjsip(28477): 02:38:06.184 tsx0x674c8c Incoming Response msg 200/REGISTER/cseq=25102 (rdata0x46c3e4) in state Calling
10-24 02:38:06.181 V/libpjsip(28477): 02:38:06.184 tsx0x674c8c State changed from Calling to Completed, event=RX_MSG
10-24 02:38:06.181 I/libpjsip(28477): 02:38:06.184 pjsua_acc.c xxxxxxxx <sip:xxxxxxxx@sipsorcery.com>: registration success, status=200 (Ok), will re-register in 3600 seconds
=====End of Log========================
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: r3gis...@gmail.com
The last register is not an Expires 0... It's :
Contact: <sip:xxxxxxxx@xx.xx.xx.xx:43602;transport=tcp>
Contact: "xxxxxxxx" <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>;expires=0
Expires: 3600
Expires is 3600 => it also update the expires of latest local register to 0... But actually it is 3600 ! it applies for the contact <sip:xxxxxxxx@xx.xx.xx.xx:43602;transport=tcp> (the first contact in the list).
This one is not present in the trace you posted on sipsorcery forum.
Why this last one is not transmitted to the server... that's the question.
Or more likely it's the first contact header that is eaten by the server. I'm not a SIP specialist (all sip stuff are done by pjsip guys),
but I think that as in HTTP mutiple header fields with the same name should be allowed by the server.
So here if what you get on sip sorcery traces :
Contact: "xxxxxxxx" <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>;expires=0
Max-Forwards: 69
User-Agent: CSipSimple
Expires: 300
Correspond to what I send :
Contact: <sip:xxxxxxxx@xx.xx.xx.xx:43602;transport=tcp>
Contact: "xxxxxxxx" <sip:xxxxxxxx@192.168.1.131:5060;transport=TCP>;expires=0
Expires: 3600
There is a missing contact header that does the difference !
(Thanks to your logs I've understood a bug open times ago but that is absolutely not related ;) -- about callerID ;) ).
I've tested with an OpenSIP server and it works properly with 2 contact header field.
Last question, (just for my information), I guess you are using Advanced or Expert account. Are you using SIP Proxy field or Force contact field? (Well force contact should solve your problem.. but will implies you already know your public IP... so not a good solution).
Just if you could do a test having a look at the same time to sipsorcery and csipsimple logs, checking CSeq ids to check that the last REGISTER sent has its first contact eaten by sipsorcery server... I think that it should be reported to sip sorcery guys. If they say that's not a standard way (not accepted by RFC) to send contact field I'll report back to pjsip guys to ask them why they are doing something not written in RFC.
SipSorcery guys maybe only manage comma separated contact field, but my understand of the RFC is that this *is* the exception while expanded 2 contact entries is normal.... but I can misunderstood, again I'm not a sip specialist and I've just waking up ;) .
*If I'm right*, they should really consider making their server support multiple fields entries with same names, else their server doesn't respect SIP RFC.
Keep me in touch.
(I reopen the bug in case it's in pjsip side that there is something wrong or something I can do on my side to provide an option for making it comma separated).
Status: Started
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: jac...@gmail.com
You have a very good point. I did new trace logs on both sides of CSipSimple and Sipsorcery, and verified that Sipsorcery does eat the first Contact header of the two in the second Register. I will report the issue to Sipsorcery. Aaron should be able to fix the issue or give a good explanation if his implementation is more "standard".
I did not use the SIP Proxy field unless the provider requires it. I did not use the Force contact either because the IP of the wireless data is dynamic. I'll keep you updated.
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: r3gis...@gmail.com
@jack : Aaron has updated the sipsorcery software. Could you try to see if it's better now?
Let us know (here or on sipsorcery forum, I've created a forum account to be able to talk directly to sipsorcery support if needed ;) ).
Thx a lot for reporting that point.
Status: Fixed
View and moderate all "tickets Discussion" comments posted by this user
Mark all as spam, and block user from posting to "Tickets"
Originally posted by: jac...@gmail.com
I just tried it and took a look at the SIP trace. I can confirm it has been fixed. Thanks for pursuing on the issue and the great job done @CSipSimple.