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: [email protected]
[mailto:[email protected]] On Behalf Of
Bram Peeters
Sent: woensdag 7 oktober 2015 15:32
To: [email protected]
Subject: [Linphone-users] Linphone keeps sending register messages
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
