Hi, I am using linphone 3.8.5 on a windows 7 pc with ip address 10.1.3.37 (one of several nics) to connect to a openwrt/asteriks sip server running on 10.1.3.200.
For some reason, linphone keeps sending register messages even though asteriks OK's them. Eg a wireshark (overview) log from the pc running linphone shows: 10.1.3.37->10.1.3.200 SIP 671 Request: REGISTER sip:10.1.3.200 ([1]) 10.1.3.200->10.1.3.37 SIP 626 Status:401 Unauthorized (0 bindings) 10.1.3.37->10.1.3.200 SIP 671 Request: REGISTER sip:10.1.3.200 10.1.3.200->10.1.3.37 SIP 562 Request: OPTIONS sip:[email protected] 10.1.3.200->10.1.3.37 SIP 522 Status: 200 OK (1 bindings) 10.1.3.37->10.1.3.200 SIP 299 Status: 200 OK This is immediately followed by another run of that same sequence (Note: [1] already contains the 'Authorization' part because it is not the first request message, but it is stilled flagged as unauthorized by asterisk probably because it reuses the same auth info as the previous register message (?)) The same sequence can be found in the asterisk debug logs: <--- SIP read from UDP:10.1.3.37:5060 ---> REGISTER sip:10.1.3.200 SIP/2.0 Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.nrn1PrqNK;rport From: <sip:[email protected]>;tag=G-i3nv0qe To: sip:[email protected] CSeq: 62044 REGISTER Call-ID: QS4qjJyxxk Max-Forwards: 70 Supported: outbound Accept: application/sdp, text/plain, application/vnd.gsma.rcs-ft-http+xml Contact: <sip:[email protected]>;+sip.instance="<urn:uuid:62fc6856-74fb-42cb-9fe4-8058743c792a>" Expires: 3600 User-Agent: Linphone/3.8.5 (belle-sip/1.4.1) Authorization: Digest realm="asterisk", nonce="035b046f", algorithm=MD5, username="77", uri="sip:10.1.3.200", response="dce8290e1c9f773f58ed45471024be0e" <-------------> --- (13 headers 0 lines) --- Sending to 10.1.3.37:5060 (NAT) <--- Transmitting (NAT) to 10.1.3.37:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.nrn1PrqNK;received=10.1.3.37;rport=5060 From: <sip:[email protected]>;tag=G-i3nv0qe To: sip:[email protected];tag=as6c3bca9e Call-ID: QS4qjJyxxk CSeq: 62044 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="49ab3765", stale=true Content-Length: 0 <------------> Scheduling destruction of SIP dialog 'QS4qjJyxxk' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:10.1.3.37:5060 ---> REGISTER sip:10.1.3.200 SIP/2.0 Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.UJpKHfkZN;rport From: <sip:[email protected]>;tag=G-i3nv0qe To: sip:[email protected] CSeq: 62045 REGISTER Call-ID: QS4qjJyxxk Max-Forwards: 70 Supported: outbound Accept: application/sdp, text/plain, application/vnd.gsma.rcs-ft-http+xml Contact: <sip:[email protected]>;+sip.instance="<urn:uuid:62fc6856-74fb-42cb-9fe4-8058743c792a>" Expires: 3600 User-Agent: Linphone/3.8.5 (belle-sip/1.4.1) Authorization: Digest realm="asterisk", nonce="49ab3765", algorithm=MD5, username="77", uri="sip:10.1.3.200", response="0b35c87e55aaaea646984f3529dad85d" <-------------> --- (13 headers 0 lines) --- Sending to 10.1.3.37:5060 (NAT) Reliably Transmitting (NAT) to 10.1.3.37:5060: OPTIONS sip:[email protected] SIP/2.0 Via: SIP/2.0/UDP 10.1.3.200:5060;branch=z9hG4bK17d8fa03;rport Max-Forwards: 70 From: "asterisk" <sip:[email protected]>;tag=as7b396113 To: <sip:[email protected]> Contact: <sip:[email protected]:5060> Call-ID: [email protected]:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.8.7.1 Date: Sat, 05 May 2012 21:04:08 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- <--- Transmitting (NAT) to 10.1.3.37:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.UJpKHfkZN;received=10.1.3.37;rport=5060 From: <sip:[email protected]>;tag=G-i3nv0qe To: sip:[email protected];tag=as6c3bca9e Call-ID: QS4qjJyxxk CSeq: 62045 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 3600 Contact: <sip:[email protected]>;expires=3600 Date: Sat, 05 May 2012 21:04:08 GMT Content-Length: 0 <------------> Scheduling destruction of SIP dialog 'QS4qjJyxxk' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:10.1.3.37:5060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.3.200:5060;branch=z9hG4bK17d8fa03;rport=1026 From: "asterisk" <sip:[email protected]>;tag=as7b396113 To: <sip:[email protected]>;tag=MESi8 Call-ID: [email protected]:5060 CSeq: 102 OPTIONS <-------------> --- (6 headers 0 lines) --- Really destroying SIP dialog '[email protected]:5060' Method: OPTIONS [ And it immediately continues (first one with the same nonce): ] <--- SIP read from UDP:10.1.3.37:5060 ---> REGISTER sip:10.1.3.200 SIP/2.0 Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.t41NI6mn1;rport From: <sip:[email protected]>;tag=G-i3nv0qe To: sip:[email protected] CSeq: 62046 REGISTER Call-ID: QS4qjJyxxk Max-Forwards: 70 Supported: outbound Accept: application/sdp, text/plain, application/vnd.gsma.rcs-ft-http+xml Contact: <sip:[email protected]>;+sip.instance="<urn:uuid:62fc6856-74fb-42cb-9fe4-8058743c792a>" Expires: 3600 User-Agent: Linphone/3.8.5 (belle-sip/1.4.1) Authorization: Digest realm="asterisk", nonce="49ab3765", algorithm=MD5, username="77", uri="sip:10.1.3.200", response="0b35c87e55aaaea646984f3529dad85d" <-------------> --- (13 headers 0 lines) --- Sending to 10.1.3.37:5060 (NAT) <--- Transmitting (NAT) to 10.1.3.37:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.t41NI6mn1;received=10.1.3.37;rport=5060 From: <sip:[email protected]>;tag=G-i3nv0qe To: sip:[email protected];tag=as6c3bca9e Call-ID: QS4qjJyxxk CSeq: 62046 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6395e8c4", stale=true Content-Length: 0 <------------> [etc...] I tried gathering debug info from linphones end, but the method described in https://lists.gnu.org/archive/html/linphone-users/2012-03/msg00020.html does not seem to work anymore (linphone just immediately crashes even before the gui appears). Any info on how to do this on windows these days is appreciated :) But in the meantime I grabbed to following snippit from the debug window (note: a different iteration then the one from asteriks, they fly by really fast ;p ): message: 2015-10-07 15:21:07:876 Changing [client] [REGISTER] transaction [03447248], from state [COMPLETED] to [TERMINATED] message: 2015-10-07 15:21:07:876 Client internal REGISTER transaction [03447248] terminated message: 2015-10-07 15:21:07:905 channel [0344AFE8]: received [482] new bytes from [UDP://10.1.3.200:1024]: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.~p1S77YhH;received=10.1.3.37;rport=5060 From: <sip:[email protected]>;tag=1tpWmNlhF To: sip:[email protected];tag=as1eefda73 Call-ID: TtysfD1gLH CSeq: 20133 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 3600 Contact: <sip:[email protected]>;expires=3600 Date: Sun, 29 Apr 2012 19:07:13 GMT Content-Length: 0 message: 2015-10-07 15:21:07:905 channel [0344AFE8] [482] bytes parsed message: 2015-10-07 15:21:07:905 Found transaction matching response. message: 2015-10-07 15:21:07:905 Changing [client] [REGISTER] transaction [03447068], from state [TRYING] to [COMPLETED] message: 2015-10-07 15:21:07:905 Refresher [03446AC8]: contact address [10.1.3.37:5060] does not match channel address[(null):0]. message: 2015-10-07 15:21:07:905 belle_sip_refresher_start(): refresher [03446AC8] is resubmitting request because contact sent was not correct in original request. message: 2015-10-07 15:21:07:906 Auth info found for [77] realm [asterisk] message: 2015-10-07 15:21:07:906 Changing [client] [REGISTER] transaction [034470C8], from state [INIT] to [TRYING] message: 2015-10-07 15:21:07:906 channel [03421138]: message sent to [UDP://10.1.3.200:5060], size: [631] bytes REGISTER sip:10.1.3.200 SIP/2.0 Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.oQEynrqlP;rport From: <sip:[email protected]>;tag=1tpWmNlhF To: sip:[email protected] CSeq: 20134 REGISTER Call-ID: TtysfD1gLH Max-Forwards: 70 Supported: outbound Accept: application/sdp, text/plain, application/vnd.gsma.rcs-ft-http+xml Contact: <sip:[email protected]>;+sip.instance="<urn:uuid:62fc6856-74fb-42cb-9fe4-8058743c792a>" Expires: 3600 User-Agent: Linphone/3.8.5 (belle-sip/1.4.1) Authorization: Digest realm="asterisk", nonce="277674ca", algorithm=MD5, username="77", uri="sip:10.1.3.200", response="d91efa320a7eb039766f7ab022fc7c58" message: 2015-10-07 15:21:07:906 Changing [client] [REGISTER] transaction [03447008], from state [COMPLETED] to [TERMINATED] message: 2015-10-07 15:21:07:906 Client internal REGISTER transaction [03447008] terminated message: 2015-10-07 15:21:07:906 Garbage collecting unowned object of type belle_sip_header_contact_t message: 2015-10-07 15:21:07:935 channel [0344AFE8]: received [486] new bytes from [UDP://10.1.3.200:1024]: SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.oQEynrqlP;received=10.1.3.37;rport=5060 From: <sip:[email protected]>;tag=1tpWmNlhF To: sip:[email protected];tag=as1eefda73 Call-ID: TtysfD1gLH CSeq: 20134 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="313657f1", stale=true Content-Length: 0 message: 2015-10-07 15:21:07:935 channel [0344AFE8] [486] bytes parsed message: 2015-10-07 15:21:07:935 Found transaction matching response. message: 2015-10-07 15:21:07:935 Changing [client] [REGISTER] transaction [034470C8], from state [TRYING] to [COMPLETED] message: 2015-10-07 15:21:07:935 Auth info found for [77] realm [asterisk] message: 2015-10-07 15:21:07:936 Changing [client] [REGISTER] transaction [03447248], from state [INIT] to [TRYING] message: 2015-10-07 15:21:07:936 channel [03421138]: message sent to [UDP://10.1.3.200:5060], size: [631] bytes REGISTER sip:10.1.3.200 SIP/2.0 Via: SIP/2.0/UDP 10.1.3.37:5060;branch=z9hG4bK.sPxy3XCXz;rport From: <sip:[email protected]>;tag=1tpWmNlhF To: sip:[email protected] CSeq: 20135 REGISTER Call-ID: TtysfD1gLH Max-Forwards: 70 Supported: outbound Accept: application/sdp, text/plain, application/vnd.gsma.rcs-ft-http+xml Contact: <sip:[email protected]>;+sip.instance="<urn:uuid:62fc6856-74fb-42cb-9fe4-8058743c792a>" Expires: 3600 User-Agent: Linphone/3.8.5 (belle-sip/1.4.1) Authorization: Digest realm="asterisk", nonce="313657f1", algorithm=MD5, username="77", uri="sip:10.1.3.200", response="55d81e85b4e3fd9e971182de93db433a" message: 2015-10-07 15:21:07:965 channel [0344AFE8]: received [520] new bytes from [UDP://10.1.3.200:1024]: OPTIONS sip:[email protected] SIP/2.0 Via: SIP/2.0/UDP 10.1.3.200:5060;branch=z9hG4bK19660533;rport Max-Forwards: 70 From: "asterisk" <sip:[email protected]>;tag=as13bb3ac8 To: <sip:[email protected]> Contact: <sip:[email protected]:5060> Call-ID: [email protected]:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.8.7.1 Date: Sun, 29 Apr 2012 19:07:13 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 message: 2015-10-07 15:21:07:966 channel [0344AFE8] [520] bytes parsed message: 2015-10-07 15:21:07:966 channel [0344AFE8]: message sent to [UDP://10.1.3.200:1024], size: [257] bytes SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.1.3.200:5060;branch=z9hG4bK19660533;rport=1024 From: "asterisk" <sip:[email protected]>;tag=as13bb3ac8 To: <sip:[email protected]>;tag=gAoXT Call-ID: [email protected]:5060 CSeq: 102 OPTIONS message: 2015-10-07 15:21:07:966 Changing [client] [REGISTER] transaction [03446F48], from state [COMPLETED] to [TERMINATED] message: 2015-10-07 15:21:07:966 Client internal REGISTER transaction [03446F48] terminated [etc...] Here I find the following suspicious: message: 2015-10-07 15:21:07:905 Refresher [03446AC8]: contact address [10.1.3.37:5060] does not match channel address[(null):0]. message: 2015-10-07 15:21:07:905 belle_sip_refresher_start(): refresher [03446AC8] is resubmitting request because contact sent was not correct in original request. But googling this message does not give me much hints what it is all about ... ? I've found a reference to someone else who had this problem but it never got resolved https://lists.gnu.org/archive/html/linphone-users/2008-07/msg00010.html Note: if I connect to sip.linphone.org (through a different nic) then it works correctly Any suggestions ? Thanks, Bram
_______________________________________________ Linphone-users mailing list [email protected] https://lists.nongnu.org/mailman/listinfo/linphone-users
