search

BelledonneCommunications / flexisip

Linphone.org mirror for flexisip (git://git.linphone.org/flexisip.git)
http://flexisip.org
GNU Affero General Public License v3.0
140 stars 68 forks source link

Flexisip not sending register #96

Open slayerphil opened 4 years ago

slayerphil commented 4 years ago

After about a day, my phones stop being able to register through the proxy, if I restart Flexisip or reboot Fusionpbx the app connects fine again. It's as though the connection between Flexisip and Fusionpbx stops, then reconnects when either is restarted. I've whitelisted IP's in both firewalls and Ive had a constant SIP ping (on 5061) running the whole time and it's solid.. but then after a period Flexisip just stops sending the requests on.

When the issue is happens, the log ends here:

REGISTER sip:sip-server.example.com SIP/2.0
Via: SIP/2.0/TLS 10.94.12.49:53429;alias;branch=z9hG4bK.HDEraPRJl;rport=42928;received=z.z.z.z
From: <sip:056XXXXXXXX@sip-server.example.com>;tag=omfftGlf4
To: sip:056XXXXXXXX@sip-server.example.com
CSeq: 20 REGISTER
Call-ID: 1xFiRMe-dt
Max-Forwards: 69
Supported: replaces, outbound, gruu
Accept: application/sdp, text/plain, application/vnd.gsma.rcs-ft-http+xml
Contact: <sip:056XXXXXXXX@flexisip.example.com:5060;fs-conn-id=a15b121e06d1a5db;CtRt725eff5ac1e5fa8e=tls:sip-server.example.com>;+sip.instance="<urn:uuid:8094365d-a4a3-0023-8c07-272bb75a6203>";+org.linphone.specs="ephemeral,groupchat,lime"
Expires: 2147483647
User-Agent: SoftphoneiOS/1.0.13 () LinphoneSDK/4.4.0-alpha.169+6f910f0
Content-Length: 0
Path: <sips:flexisip.example:5061;fs-proxy-id=725eff5ac1e5fa8e;lr>
2020-06-19 09:44:38:482 flexisip-debug-Message is sent through an outgoing transaction.
2020-06-19 09:44:38:482 flexisip-debug-tport_tsend(0x556755991ca0) tpn = tls/1.2.3.4:5061
2020-06-19 09:44:38:482 flexisip-debug-tport_queue(0x556755991ca0): queueing 0x556755ac9910 for tls/1.2.3.4:5061
2020-06-19 09:44:38:482 flexisip-debug-nta: sent REGISTER (20) to tls/1.2.3.4:5061
2020-06-19 09:44:38:482 flexisip-debug-tport_pend(0x556755991ca0): pending 0x556755ac9910 for tls/1.2.3.4:5061 (already 0)
2020-06-19 09:44:38:483 flexisip-debug-nta: timer set to 32000 ms
2020-06-19 09:44:38:483 flexisip-debug-Terminate SipEvent 0x556755ac8e80
2020-06-19 09:44:38:483 flexisip-debug-tport(0x556755aa7140): reset timer
2020-06-19 09:44:40:505 flexisip-debug-Call id 243272152

When everything is working correctly I see this:

REGISTER sip:sip-server.example.com SIP/2.0
Via: SIP/2.0/TLS 10.94.12.49:53437;alias;branch=z9hG4bK.PYyczzPIP;rport=46579;received=z.z.z.z
From: <sip:056XXXXXXXX@sip-server.example.com>;tag=wGxJiQDwA
To: sip:056XXXXXXXX@sip-server.example.com
CSeq: 20 REGISTER
Call-ID: KLTYlKZXQE
Max-Forwards: 69
Supported: replaces, outbound, gruu
Accept: application/sdp, text/plain, application/vnd.gsma.rcs-ft-http+xml
Contact: <sip:056XXXXXXXX@flexisip.example.com:5060;fs-conn-id=613eacdfdfbe933d;CtRt725eff5ac1e5fa8e=tls:sip-server.example.com>;+sip.instance="<urn:uuid:8094365d-a4a3-0023-8c07-272bb75a6203>";+org.linphone.specs="ephemeral,groupchat,lime"
Expires: 2147483647
User-Agent: SoftphoneiOS/1.0.13 () LinphoneSDK/4.4.0-alpha.169+6f910f0
Content-Length: 0
Path: <sips:flexisip.example.com:5061;fs-proxy-id=725eff5ac1e5fa8e;lr>
2020-06-19 09:46:26:875 flexisip-debug-Message is sent through an outgoing transaction.
2020-06-19 09:46:26:875 flexisip-debug-tport_tsend(0x56010de19e10) tpn = tls/x.x.x.x:5061
2020-06-19 09:46:26:875 flexisip-debug-tport_tls_writevec: vec 0x56010de1ad10 0x56010de27760 978 (978)
2020-06-19 09:46:26:875 flexisip-debug-tport_tls_writevec: vec 0x56010de1ad10 0x56010de2b908 2 (2)
2020-06-19 09:46:26:876 flexisip-debug-tport_vsend returned 980
2020-06-19 09:46:26:876 flexisip-debug-tport(0x56010de19e10): reset timer
2020-06-19 09:46:26:876 flexisip-debug-nta: sent REGISTER (20) to tls/x.x.x.x:5061
2020-06-19 09:46:26:876 flexisip-debug-tport_pend(0x56010de19e10): pending 0x56010de29130 for tls/x.x.x.x:5061 (already 0)
2020-06-19 09:46:26:876 flexisip-debug-Terminate SipEvent 0x56010de30980
2020-06-19 09:46:26:876 flexisip-debug-tport(0x56010de19b10): reset timer
2020-06-19 09:46:26:877 flexisip-debug-tport_wakeup(0x56010de19e10): events IN
2020-06-19 09:46:26:877 flexisip-debug-tport_recv_event(0x56010de19e10)
2020-06-19 09:46:26:877 flexisip-debug-tport_tls_recv(0x56010de19e10): tls_read() returned 779
2020-06-19 09:46:26:877 flexisip-debug-tport_recv_iovec(0x56010de19e10) msg 0x56010de27b70 from (tls/x.x.x.x:5061) has 779 bytes, veclen = 1
2020-06-19 09:46:26:877 flexisip-debug-tport_deliver(0x56010de19e10): msg 0x56010de27b70 (779 bytes) from tls/x.x.x.x:5061 next=(nil)
2020-06-19 09:46:26:877 flexisip-debug-nta: received 401 Unauthorized for REGISTER (20)
2020-06-19 09:46:26:877 flexisip-debug-nta: 401 Unauthorized is going to a transaction
2020-06-19 09:46:26:877 flexisip-debug-nta_outgoing: RTT is 1.959 ms
2020-06-19 09:46:26:877 flexisip-debug-tport_release(0x56010de19e10): 0x56010de29130 by 0x56010de27040 with 0x56010de27b70
2020-06-19 09:46:26:877 flexisip-debug-OutgoingTransaction callback 0x56010de2c710
2020-06-19 09:46:26:877 flexisip-debug-New SipEvent 0x56010de1e160 - 0x56010de27b70
2020-06-19 09:46:26:877 flexisip-debug-Receiving new Response SIP message: 401
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TLS flexisip.example.com;rport=44621;branch=z9hG4bK.mQtpK3mr28NQK7r1F8Q276FtFe;received=y.y.y.y
Via: SIP/2.0/TLS 10.94.12.49:53437;alias;branch=z9hG4bK.PYyczzPIP;rport=46579;received=z.z.z.z
From: <sip:056XXXXXXXX@sip-server.example.com>;tag=wGxJiQDwA
To: <sip:056XXXXXXXX@sip-server.example.com>;tag=1mpQDDHK6QNZj
Call-ID: KLTYlKZXQE
CSeq: 20 REGISTER
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, PRACK, NOTIFY, PUBLISH, SUBSCRIBE
Supported: precondition, 100rel, timer, path, replaces
WWW-Authenticate: Digest realm="sip-server.example.com", nonce="f580ef7c-0be5-431f-a1f5-5a55157deb1b", algorithm=MD5, qop="auth"
Content-Length: 0

I noticed there's a "received 401 Unauthorized for REGISTER" but all appears to be working.

My flexisip.conf looks like this

[global]
aliases=localhost flexisip.example.com
log-level=debug
syslog-level=debug
transports=sip:flexisip.example.com sips:flexisip.example.com;tls-verify-outgoing=0;tls-verify-outgoing=0
require-peer-certificate=false
keepalive-interval=0

[module::SanityChecker]
enabled=false

[module::MediaRelay]
enabled=true

[module::NatHelper]
enabled=false

[module::Forward]
enabled=true
default-transport=tls
route=sips:sip-server.example.com:5061

[module::DoSProtection]
enabled=false

[module::Registrar]
#enabled=false
max-expires=604800604800
enabled=true
reg-domains=sip-server.example.com
reg-on-response=true

[module::Authentication]
enabled=false

[module::Router]
filter=(is_request && request.uri.params contains 'doroute') || is_response
fork-late=true
message-delivery-timeout=604800

[module::PushNotification]
enabled=true
timeout=0
firebase=true
firebase-projects-api-keys=<key>

[module::ContactRouteInserter]
enabled=true
insert-domain=true

Running a Tcpdump on the sip server, I see nothing hit the box (when the issue arises)

While Netstat always shows an established connection

tcp 0 0 x.x.x.x:5061 y.y.y.y:47737 ESTABLISHED

It's as though after a period of time Flexisip just stops sending traffic to the SIP server.