|
From: | Bram Peeters |
Subject: | Re: [Linphone-users] Linphone keeps sending register messages |
Date: | Tue, 13 Oct 2015 14:23:53 +0000 |
Hi, I looked at what is happing in linphone for my infinite registeration messages problem described below. The problem is detected in 'is_contact_address_acurate' where the following ports and ip addresses are compared: int channel_public_port = refresher->transaction->base.channel->public_port; int contact_port = belle_sip_uri_get_listening_port(belle_sip_header_address_get_uri(BELLE_SIP_HEADER_ADDRESS(contact))); const char* channel_public_ip = refresher->transaction->base.channel->public_ip; const char* contact_ip = belle_sip_uri_get_host(belle_sip_header_address_get_uri(BELLE_SIP_HEADER_ADDRESS(contact))); Here, the refresher->transaction->base.channel->public_port and refresher->transaction->base.channel->public_ip are never set. The only place I can find where public port and ip are configured is when an incoming packet is processed.
The call stack is then: linphone_core_iterate->sal_iterate->belle_sip_main_loop_sleep->belle_sip_main_loop_run->belle_sip_main_loop_iterate ->on_udp_data->belle_sip_channel_process_data->on_udp_data->belle_sip_channel_process_read_data->belle_sip_channel_process_stream ->belle_sip_channel_parse_stream->belle_sip_channel_message_ready->belle_sip_channel_learn_public_ip_port When such an incoming packet arrives, in 'on_udp_data' there is a check to see to which potential existing channel the packet belongs (and it is for this channel that the public
port and ip are set in 'belle_sip_channel_learn_public_ip_port'). err=recvfrom(lp->sock,(char*)buf,sizeof(buf),MSG_PEEK,(struct sockaddr*)&addr,&addrlen); ... struct addrinfo ai={0}; /*preserve the V4 mapping*/ ai.ai_family=addr.ss_family; ai.ai_addr=(struct sockaddr*)&addr; ai.ai_addrlen=addrlen; chan=_belle_sip_listening_point_get_channel((belle_sip_listening_point_t*)lp,NULL,&ai); This function compares the current_peer->ai_addr of each of the existing channels (only 1 in my case, the channel of the refresher) with the provided
ai->ai_addr parameter (cfr 'belle_sip_channel_matches'). In my case, the match with the existing refresher channel fails (null is returned), because the peer details of the refresher are 10.1.3.200, port 5060 While the asterisk sip server's reply comes from
10.1.3.200, port 1024 The result is a new channel is created in 'on_udp_data' : if (chan==NULL){ /*TODO: should rather create the channel with real local ip and port and not just 0.0.0.0"*/ chan=belle_sip_channel_new_udp_with_addr(lp->base.stack ,lp->sock ,belle_sip_uri_get_host(lp->base.listening_uri) ,belle_sip_uri_get_port(lp->base.listening_uri) ,&ai); And this has the effect that the public ip/port of the refresher channel are never set and I end up with null/0 values. Question: how is this supposed to work normally? Should the server reply using port 5060 io 1024 (and do I have a configuration problem in my asterisk
server causing it to reply using a 'random' port 1024 io 5060). Or is it OK for the server to reply using a different port, and is there a different mechanism that should set the public port/ip of the refresher ? Which
one ? Regards Bram
From: linphone-users-bounces+address@hidden
[mailto:linphone-users-bounces+address@hidden On Behalf Of
Bram Peeters 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:address@hidden 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:address@hidden>;tag=G-i3nv0qe To: sip:address@hidden 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:address@hidden>;+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:address@hidden>;tag=G-i3nv0qe To: sip:address@hidden;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:address@hidden>;tag=G-i3nv0qe To: sip:address@hidden 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:address@hidden>;+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:address@hidden SIP/2.0 Via: SIP/2.0/UDP 10.1.3.200:5060;branch=z9hG4bK17d8fa03;rport Max-Forwards: 70 From: "asterisk" <sip:address@hidden>;tag=as7b396113 To: <sip:address@hidden> Contact: <sip:address@hidden:5060> Call-ID: address@hidden: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:address@hidden>;tag=G-i3nv0qe To: sip:address@hidden;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:address@hidden>;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:address@hidden>;tag=as7b396113 To: <sip:address@hidden>;tag=MESi8 Call-ID: address@hidden:5060 CSeq: 102 OPTIONS <-------------> --- (6 headers 0 lines) --- Really destroying SIP dialog 'address@hidden: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:address@hidden>;tag=G-i3nv0qe To: sip:address@hidden 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:address@hidden>;+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:address@hidden>;tag=G-i3nv0qe To: sip:address@hidden;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:address@hidden>;tag=1tpWmNlhF To: sip:address@hidden;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:address@hidden>;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:address@hidden>;tag=1tpWmNlhF To: sip:address@hidden 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:address@hidden>;+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:address@hidden>;tag=1tpWmNlhF To: sip:address@hidden;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:address@hidden>;tag=1tpWmNlhF To: sip:address@hidden 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:address@hidden>;+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:address@hidden SIP/2.0 Via: SIP/2.0/UDP 10.1.3.200:5060;branch=z9hG4bK19660533;rport Max-Forwards: 70 From: "asterisk" <sip:address@hidden>;tag=as13bb3ac8 To: <sip:address@hidden> Contact: <sip:address@hidden:5060> Call-ID: address@hidden: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:address@hidden>;tag=as13bb3ac8 To: <sip:address@hidden>;tag=gAoXT Call-ID: address@hidden: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
|
[Prev in Thread] | Current Thread | [Next in Thread] |