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 67 forks source link

Linphone <-> Flexisip <-> FreeSWITCH #49

Open MDevG opened 5 years ago

MDevG commented 5 years ago

Hi All,

I've been trying to use Flexisip as a push gateway in order to be able to call and send messages to our iOS devices running Linphone.

The backend VOIP is FreeSWITCH. I have tried FreeSWITCH 1.4 and 1.8 and I cannot get Flexisip to send the push notification to the iOS device no matter what I do.

Here are the things that have worked so far:

1) I have confirmed that the VOIP certificate is OK because I am able to send push notifications using flexisip_pusher.

2) If I use Flexisip as a full SIP (the devices only register in Flexisip using the userdb.conf file), Flexisip successfully sends a push notification to wake up the device if it is suspended. In other words, without FreeSWITCH into the equation, everything works correctly (including waking up the device via push).

Unfortunately, if I add into this equation the FreeSWITCH backend server, the registration part works (the device gets registered into FreeSWITCH via Flexisip) but when a device is asleep, Flexisip does not send the push notification (it does not even try to send it as I've noted from the logs) -- it just shows a CONNECTION REFUSED error like it is trying to connect to the device.

There are no attempts at forking the call or anything, it is like it does not expect to send the push notification.

The Linphone client has the "Outbound proxy" set to ON and also Push Notifications are enabled.

The domain is set to the IP of the backend SIP server (FreeSWITCH) while the proxy is set to the IP of the Flexisip server.

The setup is done via VPN so the IPs are as follows:

Backend SIP Server "FreeSWITCH": 10.8.0.1 Flexisip Server: 10.8.0.93

The devices are also in the VPN and get assigned IPs such as 10.8.0.14 and variations.

I have tried all sorts of variations of the flexisip.conf file such as enabling/disabling NAT, toggling insert-domain of the "ContactRouteInserter" between true and false, changing the "Forward" module's "params-to-remove" from "pn-tok pn-type app-id pn-msg-str pn-call-str pn-call-snd pn-msg-snd pn-timeout" to no value, turning on/off authentication, adding all IPs to the "trusted hosts", turning to false/true the "reg-on-response" key of the Registrar module, absolutely nothing works, it refuses to send the push even though I can see in the logs that the devices are associated with the correct TOKENs Ff both the devices are online, then everything is OK.

I have a minimal config file now that I have confirmed it works and sends pushes with only Flexisip running as a SIP and that is adapted for the Linphone<-->Flexisip<-->FreeSWITCH scenario that looks like this:

=== [global] debug=true aliases=10.8.0.93 transports=sip:*;maddr=10.8.0.93

[module::Registrar] enabled=true reg-domains=* db-implementation=internal max-expires=604800 reg-on-response=true

[module::MediaRelay] enabled=true

[module::Authentication] enabled=true auth-domains=* db-implementation=file datasource=/etc/flexisip/userdb.conf trusted-hosts=10.8.0.95 10.8.0.93 10.8.0.1 10.8.0.2 10.8.0.3 10.8.0.4 10.8.0.5 10.8.0.6 10.8.0.7 10.8.0.8 10.8.0.9 10.8.0.10 10.8.0.11 10.8.0.12 10.8.0.13 10.8.0.14 10.8.0.15 10.8.0.16 10.8.0.17 10.8.0.18 10.8$

[module::Router] fork-late=true message-delivery-timeout=604800 filter=

filter=(is_request && request.uri.params contains 'doroute') || is_response

enabled=true

[module::PushNotification] enabled=true timeout=1 max-queue-size=10 apple=true apple-certificate-dir=/etc/flexisip/apn no-badge=false

[module::NatHelper] enabled=false filter= !(user-agent contains 'No NatHelper') contact-verified-param=verified

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

[module::Forward] enabled=true filter= route= add-path=true rewrite-req-uri=false default-transport=tcp

params-to-remove=pn-tok pn-type app-id pn-msg-str pn-call-str pn-call-snd pn-msg-snd pn-timeout

params-to-remove=

===

Here are the logs of the Flexisip instance (with sensitive info removed).

The registration sequences (which is successful) looks like this:

======= SIP/2.0 200 OK Via: SIP/2.0/TCP 10.8.0.93;rport=36677;branch=z9hG4bK.c031HyZDmpU18Hpy4yycc1K66D Via: SIP/2.0/TCP 10.8.0.6:54802;alias;branch=z9hG4bK.B0lOaPbNq;rport=54802 From: "iPad" sip:1001@10.8.0.1;tag=piM7JmFTx To: "iPad" sip:1001@10.8.0.1;tag=Qm6gXp7XKZrZc Call-ID: YlYsn6jEoC CSeq: 24 REGISTER Contact: sip:1001@10.8.0.93:5060;app-id=<the-app-id;pn-type=apple;pn-tok=;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;CtRte50308eb4c019124=tcp:10.8.0.6:54675>;expires=975134 Contact: sip:1001@10.8.0.93:5060;app-id=<the-app-id;pn-type=apple;pn-tok=;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;CtRte50308eb4c019124=tcp:10.8.0.6:54800>;expires=999864 Contact: sip:1001@10.8.0.93:5060;app-id=<the-app-id;pn-type=apple;pn-tok=;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;CtRte50308eb4c019124=tcp:10.8.0.6:54802>;expires=1000000 Date: Thu, 10 Jan 2019 17:25:46 GMT User-Agent: FreeSWITCH-mod_sofia/1.4.20+git~20150730T173112Z~367848e07e~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Path: ;transport=tcp;fs-proxy-id=e50308eb4c019124;lr Content-Length: 0

The extension 1001 is configured in FreeSWITCH that again, resides on 10.8.0.1. Flexisip runs on 10.8.0.93. The IP address of 10.8.0.6 is the actual iOS device running Linphone and having configured the 1001 extension in it with push enabled, outbound proxy on and having the domain set to 10.8.0.1 and proxy to 10.8.0.93.

This device will now attempt to call the extension 1000 which is in the same scenario as 1001 except that it has a different IP address which is 10.8.0.10.

Here are the logs when attempting to call from 1001 to 1000, having 1000 in sleep mode (theoretically, it should send the push notification).

When dialing, the just "waits" there, it does not ring, it doesn't do anyhing, and the logs are the following:

The "INVITE" part looks like this:

========== INVITE sip:1000@10.8.0.1;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.8.0.6:54809;branch=z9hG4bK.nP9W1kp5a;rport=54809 From: "iPad" sip:1001@10.8.0.1;tag=~E0d46hrs To: "1000" sip:1000@10.8.0.1 CSeq: 20 INVITE Call-ID: qMaBPfVmJl Max-Forwards: 69 Supported: replaces, outbound, gruu Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Contact: sip:1001@10.8.0.6:54809;pn-silent=1;transport=tcp;+sip.instance="";+org.linphone.specs=groupchat User-Agent: ORION_iPad7.5_iOS12.1/4.0.2-176-g4f0666d0f (belle-sip/1.6.3) Content-Length: 613 Record-Route: <sip:10.8.0.93:5060;transport=tcp;lr>

v=0 o=1001 2688 2214 IN IP4 10.8.0.6 s=Talk c=IN IP4 10.8.0.93 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics a=nortpproxy:yes m=audio 43538 RTP/AVP 96 97 98 0 8 18 101 99 100 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 speex/16000 a=fmtp:97 vbr=on a=rtpmap:98 speex/8000 a=fmtp:98 vbr=on a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/48000 a=rtpmap:99 telephone-event/16000 a=rtpmap:100 telephone-event/8000 a=zrtp-hash:1.10 59032a7bf526ef1688893af78a9420c948e37fe18c645c5f7fbf41ace9d5e469 a=rtcp-fb: trr-int 1000 a=rtcp-fb: ccm tmmbr

==============

After that, the logs continue with:

========== 2019-01-10 17:35:58:323 flexisip-debug-Message is sent through an outgoing transaction. 2019-01-10 17:35:58:323 flexisip-debug-tport_tsend(0x5583df97c670) tpn = tcp/10.8.0.1:5060 2019-01-10 17:35:58:323 flexisip-debug-tport_vsend returned 1408 2019-01-10 17:35:58:323 flexisip-debug-tport(0x5583df97c670): set timer at 1800000 ms because keepalive 2019-01-10 17:35:58:323 flexisip-debug-nta: sent INVITE (20) to tcp/10.8.0.1:5060 2019-01-10 17:35:58:323 flexisip-debug-tport_pend(0x5583df97c670): pending 0x5583df981580 for tcp/10.8.0.1:5060 (already 0) 2019-01-10 17:35:58:323 flexisip-debug-Terminate SipEvent 0x5583df985660 2019-01-10 17:35:58:323 flexisip-debug-tport(0x5583df980cd0): set timer at 1772411 ms because keepalive 2019-01-10 17:35:58:325 flexisip-debug-tport_wakeup(0x5583df97c670): events IN 2019-01-10 17:35:58:325 flexisip-debug-tport_recv_event(0x5583df97c670) 2019-01-10 17:35:58:325 flexisip-debug-tport_recv_iovec(0x5583df97c670) msg 0x5583df9784a0 from (tcp/10.8.0.1:5060) has 1332 bytes, veclen = 1 2019-01-10 17:35:58:325 flexisip-debug-tport_deliver(0x5583df97c670): msg 0x5583df9784a0 (443 bytes) from tcp/10.8.0.1:5060 next=0x5583df97ac90 2019-01-10 17:35:58:325 flexisip-debug-nta: received 100 Trying for INVITE (20) 2019-01-10 17:35:58:325 flexisip-debug-nta: 100 Trying is going to a transaction 2019-01-10 17:35:58:325 flexisip-debug-nta_outgoing: RTT is 2.2 ms 2019-01-10 17:35:58:325 flexisip-debug-tport_release(0x5583df97c670): 0x5583df981580 by 0x5583df992020 with 0x5583df9784a0 (preliminary) 2019-01-10 17:35:58:325 flexisip-debug-tport_deliver(0x5583df97c670): msg 0x5583df97ac90 (889 bytes) from tcp/10.8.0.1:5060 next=(nil) 2019-01-10 17:35:58:325 flexisip-debug-nta: received 407 Proxy Authentication Required for INVITE (20) 2019-01-10 17:35:58:325 flexisip-debug-nta: 407 Proxy Authentication Required is going to a transaction 2019-01-10 17:35:58:325 flexisip-debug-tport_release(0x5583df97c670): 0x5583df981580 by 0x5583df992020 with 0x5583df97ac90 2019-01-10 17:35:58:325 flexisip-debug-tport(0x5583df973200): found 0x5583df97c670 by name tcp/10.8.0.1:5060 2019-01-10 17:35:58:325 flexisip-debug-tport(0x5583df97c670): found from primary tcp/10.8.0.1:5060 2019-01-10 17:35:58:326 flexisip-debug-tport_tsend(0x5583df97c670) tpn = tcp/10.8.0.1:5060 2019-01-10 17:35:58:326 flexisip-debug-tport_vsend returned 293 2019-01-10 17:35:58:326 flexisip-debug-tport(0x5583df97c670): set timer at 1800000 ms because keepalive 2019-01-10 17:35:58:326 flexisip-debug-nta: sent ACK (20) to tcp/10.8.0.1:5060 2019-01-10 17:35:58:326 flexisip-debug-nta: outgoing_free(0x5583df9939f0) 2019-01-10 17:35:58:326 flexisip-debug-OutgoingTransaction callback 0x5583df9824c0 2019-01-10 17:35:58:326 flexisip-debug-New SipEvent 0x5583df97b120 - 0x5583df97ac90 2019-01-10 17:35:58:326 flexisip-debug-Receiving new Response SIP message: 407 SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/TCP 10.8.0.93;rport=36677;branch=z9hG4bK.03pDvc0t4KXy44m6pK8052HHQH Via: SIP/2.0/TCP 10.8.0.6:54809;branch=z9hG4bK.nP9W1kp5a;rport=54809 From: "iPad" sip:1001@10.8.0.1;tag=~E0d46hrs To: "1000" sip:1000@10.8.0.1;tag=ZvgQBFetv6aNS Call-ID: qMaBPfVmJl CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.20+git~20150730T173112Z~367848e07e~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="10.8.0.1", nonce="30babce6-14fe-11e9-bfc1-574ba69aeda3", algorithm=MD5, qop="auth" Content-Length: 0

Then it looks like another "INVITE" takes place:

======== 2019-01-10 17:35:58:326 flexisip-debug-Invoking onResponse() on module DoSProtection 2019-01-10 17:35:58:326 flexisip-debug-Invoking onResponse() on module SanityChecker 2019-01-10 17:35:58:326 flexisip-debug-Skipping onResponse() on module GarbageIn 2019-01-10 17:35:58:326 flexisip-debug-Skipping onResponse() on module NatHelper 2019-01-10 17:35:58:326 flexisip-debug-Invoking onResponse() on module Authentication 2019-01-10 17:35:58:326 flexisip-debug-Skipping onResponse() on module Redirect 2019-01-10 17:35:58:326 flexisip-debug-Skipping onResponse() on module GatewayAdapter 2019-01-10 17:35:58:327 flexisip-debug-Skipping onResponse() on module Presence 2019-01-10 17:35:58:327 flexisip-debug-Invoking onResponse() on module Registrar 2019-01-10 17:35:58:327 flexisip-debug-Skipping onResponse() on module StatisticsCollector 2019-01-10 17:35:58:327 flexisip-debug-Invoking onResponse() on module ContactRouteInserter 2019-01-10 17:35:58:327 flexisip-debug-Invoking onResponse() on module Router 2019-01-10 17:35:58:327 flexisip-debug-Invoking onResponse() on module PushNotification 2019-01-10 17:35:58:327 flexisip-debug-Skipping onResponse() on module LoadBalancer 2019-01-10 17:35:58:327 flexisip-debug-Invoking onResponse() on module MediaRelay 2019-01-10 17:35:58:327 flexisip-debug-RelaySession [0x5583df981990]: branch corresponding to transaction [03pDvc0t4KXy44m6pK8052HHQH] removed. 2019-01-10 17:35:58:327 flexisip-debug-call context 0x5583df982590 2019-01-10 17:35:58:327 flexisip-debug-RelayedCall is terminated by final error response 2019-01-10 17:35:58:327 flexisip-debug-CallStore::remove() removing CallContext 0x5583df982590 2019-01-10 17:35:58:327 flexisip-debug-RelaySession [0x5583df981990] terminated. 2019-01-10 17:35:58:327 flexisip-debug-Front on port [32120] received [0] and sent [0] packets. 2019-01-10 17:35:58:327 flexisip-debug-Skipping onResponse() on module Transcoder 2019-01-10 17:35:58:327 flexisip-debug-Invoking onResponse() on module Forward 2019-01-10 17:35:58:328 flexisip-debug-Sending response: (via popped) SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/TCP 10.8.0.6:54809;branch=z9hG4bK.nP9W1kp5a;rport=54809 From: "iPad" sip:1001@10.8.0.1;tag=~E0d46hrs To: "1000" sip:1000@10.8.0.1;tag=ZvgQBFetv6aNS Call-ID: qMaBPfVmJl CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.20+git~20150730T173112Z~367848e07e~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="10.8.0.1", nonce="30babce6-14fe-11e9-bfc1-574ba69aeda3", algorithm=MD5, qop="auth" Content-Length: 0

The logs continue with:

======== 2019-01-10 17:35:58:328 flexisip-debug-Response is sent through an incoming transaction. 2019-01-10 17:35:58:328 flexisip-debug-tport_tsend(0x5583df980cd0) tpn = TCP/10.8.0.6:54809 2019-01-10 17:35:58:328 flexisip-debug-tport_vsend returned 807 2019-01-10 17:35:58:328 flexisip-debug-tport(0x5583df980cd0): set timer at 1800000 ms because keepalive 2019-01-10 17:35:58:328 flexisip-debug-nta: sent 407 Proxy Authentication Required for INVITE (20) 2019-01-10 17:35:58:328 flexisip-debug-nta_incoming_destroy: 0x5583df97caf0 2019-01-10 17:35:58:328 flexisip-debug-Terminate SipEvent 0x5583df97b120 2019-01-10 17:35:58:328 flexisip-debug-nta: outgoing_free(0x5583df992020) 2019-01-10 17:35:58:328 flexisip-debug-Destroy RelayedCall 0x5583df982590 2019-01-10 17:35:58:328 flexisip-debug-CallContext 0x5583df982590 with id 108078168 destroyed. 2019-01-10 17:35:58:328 flexisip-debug-Delete IncomingTransaction 0x5583df97c4c0 2019-01-10 17:35:58:328 flexisip-debug-Delete OutgoingTransaction 0x5583df9824c0 2019-01-10 17:35:58:328 flexisip-debug-tport(0x5583df97c670): set timer at 1799998 ms because keepalive 2019-01-10 17:35:58:328 flexisip-debug-tport(0x5583df97c670): set timer at 1799998 ms because keepalive 2019-01-10 17:35:58:386 flexisip-debug-tport_wakeup(0x5583df980cd0): events IN 2019-01-10 17:35:58:387 flexisip-debug-tport_recv_event(0x5583df980cd0) 2019-01-10 17:35:58:387 flexisip-debug-tport_recv_iovec(0x5583df980cd0) msg 0x5583df998570 from (tcp/10.8.0.6:54809) has 693 bytes, veclen = 1 2019-01-10 17:35:58:387 flexisip-debug-tport_deliver(0x5583df980cd0): msg 0x5583df998570 (693 bytes) from tcp/10.8.0.6:54809 next=(nil) 2019-01-10 17:35:58:387 flexisip-debug-nta: received ACK sip:1000@10.8.0.1 SIP/2.0 (CSeq 20) 2019-01-10 17:35:58:387 flexisip-debug-nta: ACK (20) is going to INVITE (20) 2019-01-10 17:35:58:387 flexisip-debug-tport(0x5583df980cd0): set timer at 1799941 ms because keepalive 2019-01-10 17:35:58:387 flexisip-debug-tport_wakeup(0x5583df980cd0): events IN 2019-01-10 17:35:58:387 flexisip-debug-tport_recv_event(0x5583df980cd0) 2019-01-10 17:35:58:387 flexisip-debug-tport_recv_iovec(0x5583df980cd0) msg 0x5583df998570 from (tcp/10.8.0.6:54809) has 1755 bytes, veclen = 1 2019-01-10 17:35:58:387 flexisip-debug-tport_deliver(0x5583df980cd0): msg 0x5583df998570 (1755 bytes) from tcp/10.8.0.6:54809 next=(nil) 2019-01-10 17:35:58:387 flexisip-debug-nta: received INVITE sip:1000@10.8.0.1 SIP/2.0 (CSeq 21) 2019-01-10 17:35:58:388 flexisip-debug-nta: INVITE (21) to message callback 2019-01-10 17:35:58:388 flexisip-debug-New SipEvent 0x5583df982630 - msg 0x5583df998570 2019-01-10 17:35:58:388 flexisip-debug-Receiving new Request SIP message INVITE from sip:1001@10.8.0.1 :

Another "INVITE" shows up:

======== INVITE sip:1000@10.8.0.1 SIP/2.0 Via: SIP/2.0/TCP 10.8.0.6:54809;branch=z9hG4bK.NcHrTXXFC;rport=54809 From: "iPad" sip:1001@10.8.0.1;tag=~E0d46hrs To: "1000" sip:1000@10.8.0.1 CSeq: 21 INVITE Call-ID: qMaBPfVmJl Max-Forwards: 70 Route: <sip:10.8.0.93;transport=tcp;lr> Supported: replaces, outbound, gruu Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 593 Contact: sip:1001@10.8.0.6:54809;app-id=<the-app-id;pn-type=apple;pn-tok=;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;transport=tcp>;+sip.instance="";+org.linphone.specs=groupchat User-Agent: ORION_iPad7.5_iOS12.1/4.0.2-176-g4f0666d0f (belle-sip/1.6.3) Proxy-Authorization: Digest realm="10.8.0.1", nonce="30babce6-14fe-11e9-bfc1-574ba69aeda3", algorithm=MD5, username="1001", uri="sip:1000@10.8.0.1", response="d1565f19a993da6c14f7c74e03ce832c", cnonce="wWa-FsZT1TZzvfpy", nc=00000001, qop=auth

v=0 o=1001 2688 2214 IN IP4 10.8.0.6 s=Talk c=IN IP4 10.8.0.6 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7292 RTP/AVP 96 97 98 0 8 18 101 99 100 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 speex/16000 a=fmtp:97 vbr=on a=rtpmap:98 speex/8000 a=fmtp:98 vbr=on a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/48000 a=rtpmap:99 telephone-event/16000 a=rtpmap:100 telephone-event/8000 a=zrtp-hash:1.10 59032a7bf526ef1688893af78a9420c948e37fe18c645c5f7fbf41ace9d5e469 a=rtcp-fb: trr-int 1000 a=rtcp-fb: ccm tmmbr

2019-01-10 17:35:58:388 flexisip-debug-Invoking onRequest() on module DoSProtection 2019-01-10 17:35:58:388 flexisip-debug-Invoking onRequest() on module SanityChecker 2019-01-10 17:35:58:388 flexisip-debug-Skipping onRequest() on module GarbageIn 2019-01-10 17:35:58:388 flexisip-debug-Skipping onRequest() on module NatHelper 2019-01-10 17:35:58:388 flexisip-debug-Invoking onRequest() on module Authentication 2019-01-10 17:35:58:388 flexisip-debug-Allowing message from trusted host 10.8.0.6 2019-01-10 17:35:58:388 flexisip-debug-Skipping onRequest() on module Redirect 2019-01-10 17:35:58:388 flexisip-debug-Skipping onRequest() on module GatewayAdapter 2019-01-10 17:35:58:388 flexisip-debug-Skipping onRequest() on module Presence 2019-01-10 17:35:58:388 flexisip-debug-Invoking onRequest() on module Registrar 2019-01-10 17:35:58:388 flexisip-debug-Skipping onRequest() on module StatisticsCollector 2019-01-10 17:35:58:388 flexisip-debug-Invoking onRequest() on module ContactRouteInserter 2019-01-10 17:35:58:389 flexisip-debug-No countact route parameter found

The logs continue with:

=========== 2019-01-10 17:35:58:389 flexisip-debug-Invoking onRequest() on module Router 2019-01-10 17:35:58:389 flexisip-debug-Invoking onRequest() on module PushNotification 2019-01-10 17:35:58:389 flexisip-debug-Skipping onRequest() on module LoadBalancer 2019-01-10 17:35:58:389 flexisip-debug-Invoking onRequest() on module MediaRelay 2019-01-10 17:35:58:389 flexisip-debug-New IncomingTransaction 0x5583df985220 2019-01-10 17:35:58:389 flexisip-debug-nta_incoming_create: created incoming transaction 0x5583df981ae0 2019-01-10 17:35:58:389 flexisip-debug-New OutgoingTransaction 0x5583df981070 2019-01-10 17:35:58:389 flexisip-debug-CallContext 0x5583df9787e0 created 2019-01-10 17:35:58:389 flexisip-debug-New RelayedCall 0x5583df9787e0 2019-01-10 17:35:58:389 ortp-message-RtpSession bound to [0.0.0.0] ports [19954] [19955] 2019-01-10 17:35:58:389 flexisip-debug-There are now 2 relay sessions running on MediaRelayServer [0x5583df982ff0] 2019-01-10 17:35:58:389 flexisip-debug-RelaySession 0x5583df981990 destroyed 2019-01-10 17:35:58:389 flexisip-debug-There are now 1 relay sessions running. 2019-01-10 17:35:58:390 ortp-message-RtpSession bound to [0.0.0.0] ports [63006] [63007] 2019-01-10 17:35:58:390 flexisip-debug-RelaySession [0x5583df984140]: branch corresponding to transaction [K7Fge9vjQ68p27c442gj1ZgFac] added. 2019-01-10 17:35:58:390 flexisip-debug-RelayChannel [0x5583df984260] is now configured local=[10.8.0.93|19954:19955] remote=[10.8.0.6|7292:7293] dir=[SendRecv] 2019-01-10 17:35:58:390 flexisip-debug-updateIceFromOffer() this=0x5583df984260 setting ufrag, pwd to
2019-01-10 17:35:58:390 flexisip-debug-updateIceFromOffer() this=0x5583df984260 offerer state IceNone -> IceNone 2019-01-10 17:35:58:390 flexisip-debug-updateIceFromOffer() this=0x5583df994e70 offered state IceNone -> IceNone 2019-01-10 17:35:58:390 flexisip-debug-Record route added. 2019-01-10 17:35:58:390 flexisip-debug-Skipping onRequest() on module Transcoder 2019-01-10 17:35:58:390 flexisip-debug-Invoking onRequest() on module Forward 2019-01-10 17:35:58:390 flexisip-debug-Removing top route sip:10.8.0.93;transport=tcp;lr 2019-01-10 17:35:58:390 flexisip-debug-tport(0x5583df973200): found 0x5583df97c670 by name tcp/10.8.0.1:5060 2019-01-10 17:35:58:390 flexisip-debug-tport(0x5583df97c670): found from primary tcp/10.8.0.1:5060 2019-01-10 17:35:58:390 flexisip-debug-Skipping addition of record route identical to top one 2019-01-10 17:35:58:390 flexisip-debug-Removed push params from contact 2019-01-10 17:35:58:391 flexisip-debug-Sending Request SIP message to sip:1000@10.8.0.1;transport=tcp

After another "INVITE" similar to the ones above, the logs show:

========= 2019-01-10 17:35:58:391 flexisip-debug-Message is sent through an outgoing transaction. 2019-01-10 17:35:58:391 flexisip-debug-tport_tsend(0x5583df97c670) tpn = tcp/10.8.0.1:5060 2019-01-10 17:35:58:391 flexisip-debug-tport_vsend returned 1652 2019-01-10 17:35:58:391 flexisip-debug-tport(0x5583df97c670): set timer at 1800000 ms because keepalive 2019-01-10 17:35:58:391 flexisip-debug-nta: sent INVITE (21) to tcp/10.8.0.1:5060 2019-01-10 17:35:58:391 flexisip-debug-tport_pend(0x5583df97c670): pending 0x5583df998570 for tcp/10.8.0.1:5060 (already 0) 2019-01-10 17:35:58:391 flexisip-debug-Terminate SipEvent 0x5583df982630 2019-01-10 17:35:58:391 flexisip-debug-tport(0x5583df980cd0): set timer at 1799937 ms because keepalive 2019-01-10 17:35:58:392 flexisip-debug-tport_wakeup(0x5583df97c670): events IN 2019-01-10 17:35:58:392 flexisip-debug-tport_recv_event(0x5583df97c670) 2019-01-10 17:35:58:392 flexisip-debug-tport_recv_iovec(0x5583df97c670) msg 0x5583df986270 from (tcp/10.8.0.1:5060) has 443 bytes, veclen = 1 2019-01-10 17:35:58:392 flexisip-debug-tport_deliver(0x5583df97c670): msg 0x5583df986270 (443 bytes) from tcp/10.8.0.1:5060 next=(nil) 2019-01-10 17:35:58:392 flexisip-debug-nta: received 100 Trying for INVITE (21) 2019-01-10 17:35:58:392 flexisip-debug-nta: 100 Trying is going to a transaction 2019-01-10 17:35:58:392 flexisip-debug-nta_outgoing: RTT is 1.175 ms 2019-01-10 17:35:58:392 flexisip-debug-tport_release(0x5583df97c670): 0x5583df998570 by 0x5583df996f60 with 0x5583df986270 (preliminary) 2019-01-10 17:35:58:392 flexisip-debug-tport(0x5583df97c670): set timer at 1799999 ms because keepalive 2019-01-10 17:35:58:461 flexisip-debug-tport_wakeup(0x5583df98b000): events IN 2019-01-10 17:35:58:462 flexisip-debug-tport_recv_event(0x5583df98b000) 2019-01-10 17:35:58:462 flexisip-debug-tport_recv_iovec(0x5583df98b000) msg 0x5583df986270 from (tcp/10.8.0.1:50341) has 8658 bytes, veclen = 1 2019-01-10 17:35:58:462 flexisip-debug-tport_deliver(0x5583df98b000): msg 0x5583df986270 (2165 bytes) from tcp/10.8.0.1:50341 next=0x5583df989880 2019-01-10 17:35:58:462 flexisip-debug-nta: received INVITE sip:1000@10.8.0.93:5060;app-id=;pn-type=apple;pn-tok=;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;CtRte50308eb4c019124=tcp:10.8.0.10:50630 SIP/2.0 (CSeq 133234815) 2019-01-10 17:35:58:462 flexisip-debug-nta: INVITE (133234815) to message callback 2019-01-10 17:35:58:462 flexisip-debug-New SipEvent 0x5583df989e80 - msg 0x5583df986270 2019-01-10 17:35:58:462 flexisip-debug-Receiving new Request SIP message INVITE from sip:1001@10.8.0.1 : INVITE sip:1000@10.8.0.93:5060;app-id=;pn-type=apple;pn-tok=;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;CtRte50308eb4c019124=tcp:10.8.0.10:50630 SIP/2.0 Via: SIP/2.0/TCP 10.8.0.1;rport=50341;branch=z9hG4bK1cN430ZaDy29r Route: ;transport=tcp;fs-proxy-id=e50308eb4c019124;lr

Yet another INVITE with slightly different ouput afterwards:

========= To: sip:1000@10.8.0.93:5060;app-id=org.phone.phone1.voip.prod;pn-type=apple;pn-tok=<the-token;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;CtRte50308eb4c019124=tcp:10.8.0.10:50630> Call-ID: 082cdf8e-8fa1-1237-6ea1-2278d0744138 CSeq: 133234815 INVITE Contact: sip:mod_sofia@10.8.0.1:5060 User-Agent: FreeSWITCH-mod_sofia/1.4.20+git~20150730T173112Z~367848e07e~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 613 X-FS-Support: update_display,send_info Remote-Party-ID: "1001" sip:1001@10.8.0.1;party=calling;screen=yes;privacy=off

v=0 o=1001 2688 2214 IN IP4 10.8.0.6 s=Talk c=IN IP4 10.8.0.93 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics a=nortpproxy:yes m=audio 63006 RTP/AVP 96 97 98 0 8 18 101 99 100 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 speex/16000 a=fmtp:97 vbr=on a=rtpmap:98 speex/8000 a=fmtp:98 vbr=on a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/48000 a=rtpmap:99 telephone-event/16000 a=rtpmap:100 telephone-event/8000 a=zrtp-hash:1.10 59032a7bf526ef1688893af78a9420c948e37fe18c645c5f7fbf41ace9d5e469 a=rtcp-fb: trr-int 1000 a=rtcp-fb: ccm tmmbr

2019-01-10 17:35:58:462 flexisip-debug-Invoking onRequest() on module DoSProtection 2019-01-10 17:35:58:462 flexisip-debug-Invoking onRequest() on module SanityChecker 2019-01-10 17:35:58:462 flexisip-debug-Skipping onRequest() on module GarbageIn 2019-01-10 17:35:58:462 flexisip-debug-Skipping onRequest() on module NatHelper 2019-01-10 17:35:58:463 flexisip-debug-Invoking onRequest() on module Authentication 2019-01-10 17:35:58:463 flexisip-debug-Allowing message from trusted host 10.8.0.1 2019-01-10 17:35:58:463 flexisip-debug-Skipping onRequest() on module Redirect 2019-01-10 17:35:58:463 flexisip-debug-Skipping onRequest() on module GatewayAdapter 2019-01-10 17:35:58:463 flexisip-debug-Skipping onRequest() on module Presence 2019-01-10 17:35:58:463 flexisip-debug-Invoking onRequest() on module Registrar 2019-01-10 17:35:58:463 flexisip-debug-Skipping onRequest() on module StatisticsCollector 2019-01-10 17:35:58:463 flexisip-debug-Invoking onRequest() on module ContactRouteInserter 2019-01-10 17:35:58:463 flexisip-debug-Found a contact route parameter 2019-01-10 17:35:58:463 flexisip-debug-Request url changed to sip:1000@10.8.0.10:50630;app-id=;pn-type=apple;pn-tok=;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;transport=tcp;doroute 2019-01-10 17:35:58:463 flexisip-debug-Invoking onRequest() on module Router 2019-01-10 17:35:58:463 flexisip-debug-Invoking onRequest() on module PushNotification 2019-01-10 17:35:58:463 flexisip-debug-Skipping onRequest() on module LoadBalancer 2019-01-10 17:35:58:463 flexisip-debug-Invoking onRequest() on module MediaRelay 2019-01-10 17:35:58:463 flexisip-debug-New IncomingTransaction 0x5583df98ada0

Any ideas ? From what I understand, FreeSWITCH should not be configured in a certain way, Flexisip should just work ?

If the clients connect straight to FreeSWITCH (no Flexisip) everything works except the push notifications, of course.

If the clients connect straight to Flexisip ONLY, the push notifications work as well, but we are losing all the things that FreeSWITCH has to offer (dialplans, voice mail, etc.)

If the clients are in the: client <--> Flexisip <--> FreeSWITCH scenario like above, it works to call if both apps are running but if one is in the background, the push is never sent as shown above.

Any pointers ? I have been struggling with this for 20 days now. Is it even compatible with FreeSWITCH ? Or maybe someone who has it working if they would be so kind to share their flexisip.conf file ?

Thank you!

StarTeleLogic commented 5 years ago

Seems you have not done proper configuration on FS and your client end.. Also why don't you set-up a PUSH server (silent PUSH for iOS) ? with Google firebase.

Very surprise that you have wasted 20 days for 2 hours task!

tdnguyen1006 commented 5 years ago

@MDevG you can try this.

[global]

debug=true

log-level=debug

syslog-level=debug

max-log-size=100M

user-errors-logs=false

dump-corefiles=true

auto-respawn=true

aliases=localhost

default-servers=proxy

transports=sip:*

tls-certificates-dir=/etc/flexisip/tls/

tls-ciphers=HIGH:!SSLv2:!SSLv3:!TLSv1:!EXP:!ADH:!RC4:!3DES:!aNULL:!eNULL

idle-timeout=3600

keepalive-interval=1800

proxy-to-proxy-keepalive-interval=0

require-peer-certificate=false

transaction-timeout=32000

udp-mtu=1460

enable-snmp=true

unique-id=

plugins-dir=/opt/belledonne-communications/lib64/flexisip/plugins

plugins=

[cluster]

enabled=false

cluster-domain=

nodes=

internal-transport=sip:%auto:5059;transport=tcp

[mdns-register]

enabled=false

mdns-priority=0

mdns-weight=100

mdns-ttl=3600

[event-logs]

enabled=false

logger=filesystem

dir=/var/log/flexisip

database-backend=mysql

database-connection-string=db='mydb' user='myuser' password='mypass' host='myhost.com'

database-max-queue-size=100

database-nb-threads-max=10

[monitor]

enabled=false

test-interval=30

logfile=/etc/flexisip/flexisip_monitor.log

switch-port=12345

password-salt=

[stun-server]

enabled=true

bind-address=0.0.0.0

port=3478

[presence-server]

enabled=true

transports=sip:127.0.0.1:5065;transport=tcp

expires=600

notify-limit=200

leak-detector=false

long-term-enabled=true

bypass-condition=false

external-list-subscription-request=

soci-connection-string=

max-thread=50

max-thread-queue-size=50

[conference-server]

enabled=true

transport=sip:127.0.0.1:6064;transport=tcp

conference-factory-uri=

enable-one-to-one-chat-room=true

outbound-proxy=sip:127.0.0.1:5060;transport=tcp

database-backend=mysql

database-connection-string=db='mydb' user='myuser' password='mypass' host='myhost.com'

check-capabilities=true

[module::DoSProtection]

enabled=true

filter=

time-period=3000

packet-rate-limit=20

ban-time=2

iptables-chain=FLEXISIP

[module::SanityChecker]

enabled=true

filter=

[module::GarbageIn]

enabled=false

filter=false

[module::NatHelper]

enabled=true

filter= !(user-agent contains 'No NatHelper')

contact-verified-param=verified

fix-record-routes=false

fix-record-routes-policy=safe

[module::Authentication]

enabled=false

filter=

auth-domains=localhost

trusted-hosts=

db-implementation=file

datasource=

nonce-expires=3600

cache-expire=1800

no-403=false

reject-wrong-client-certificates=false

tls-client-certificate-required-subject=

new-auth-on-407=false

enable-test-accounts-creation=false

disable-qop-auth=false

available-algorithms=MD5

trust-domain-certificates=false

soci-password-request=select password, 'MD5' from accounts where login = :id and domain = :domain

soci-user-with-phone-request=

soci-users-with-phones-request=

soci-poolsize=100

soci-backend=mysql

soci-connection-string=db=mydb user=myuser password='mypass' host=myhost.com

soci-max-queue-size=1000

[module::Redirect]

enabled=false

filter=

contact=

[module::Presence]

enabled=false

filter=is_request && (request.method-name == 'PUBLISH' || request.method-name == 'NOTIFY' || request.method-name == 'SUBSCRIBE')

presence-server=sip:127.0.0.1:5065;transport=tcp

only-list-subscription=false

check-domain-in-presence-results=false

[module::Registrar]

enabled=true

filter=

reg-domains=*

reg-on-response=true

max-contacts-by-aor=12

unique-id-parameters=+sip.instance pn-tok line

max-expires=86400

min-expires=60

force-expires=-1

static-records-file=

static-records-timeout=600

db-implementation=internal

redis-server-domain=localhost

redis-server-port=6379

redis-auth-password=

redis-server-timeout=1500

redis-record-serializer=protobuf

redis-slave-check-period=60

service-route=

name-message-expires=message-expires

register-expire-randomizer-max=0

[module::StatisticsCollector]

enabled=false

filter=is_request && request.method-name == 'PUBLISH'

collector-address=

[module::Router]

enabled=true

filter=(is_request && request.uri.params contains 'doroute') || is_response

use-global-domain=false

fork=true

stateful=true

fork-late=true

fork-no-global-decline=false

treat-decline-as-urgent=false

treat-all-as-urgent=false

call-fork-timeout=90

call-fork-urgent-timeout=5

call-fork-current-branches-timeout=10

call-push-response-timeout=0

message-fork-late=true

message-delivery-timeout=3600

message-accept-timeout=15

fallback-route=

allow-target-factorization=false

generated-contact-route=

generated-contact-expected-realm=

generate-contact-even-on-filled-aor=false

preroute=

resolve-routes=false

parent-domain-fallback=false

[module::PushNotification]

enabled=true

filter=

timeout=5

max-queue-size=100

time-to-live=2592000

apple=true

apple-certificate-dir=/etc/flexisip/apn

google=true

google-projects-api-keys=

firebase=true

firebase-projects-api-keys=

windowsphone=true

windowsphone-package-sid=

windowsphone-application-secret=

no-badge=false

external-push-uri=

external-push-method=GET

[module::MediaRelay]

enabled=true

filter=

nortpproxy=nortpproxy

sdp-port-range-min=1024

sdp-port-range-max=65535

bye-orphan-dialogs=false

max-calls=0

force-relay-for-non-ice-targets=true

prevent-loops=true

early-media-relay-single=true

max-early-media-per-call=0

inactivity-period=3600

force-public-ip-for-sdp-masquerading=false

[module::Transcoder]

enabled=false

filter=

jb-nom-size=0

rc-user-agents=

audio-codecs=speex/8000 amr/8000 iLBC/8000 gsm/8000 pcmu/8000 pcma/8000 telephone-event/8000

remove-bw-limits=false

block-retransmissions=false

[module::Forward]

enabled=true

filter=

route=

add-path=true

rewrite-req-uri=false

default-transport=udp

params-to-remove=pn-tok pn-type app-id pn-msg-str pn-call-str pn-call-snd pn-msg-snd pn-timeout

[inter-domain-connections]

accept-domain-registrations=false

assume-unique-domains=false

domain-registrations=/etc/flexisip/domain-registrations.conf

verify-server-certs=true

keepalive-interval=30

reg-when-needed=false

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

I use this config and it works. The problem is incoming call drops at 30 seconds because Flexisip did not respond when PBX sent ACK packet to it. I'm still looking for a solution. If you know how to solve it, please let me know.

meetme2meat commented 4 years ago

Very surprise that you have wasted 20 days for 2 hours task

@StarTeleLogic May be because Push notification does work neither APN nor GCM (but work via flexisip_pusher)

I'm too struggling to get an answer for same question.. and I haven't seen anyone manage to solve thus far.

jsonsolanki commented 3 years ago

Hello @meetme2meat @MDevG @tdnguyen1006 @Gui13 @jehandelalune ,

I am also facing this issue. Anyone resolve this issue ? if yes then can you please help me for resolve this issue.

Thanks.

meetme2meat commented 3 years ago

@jsonsolanki Last I remember I had a header attributes issue in our SIP client which was against the Linphone requirement. After we fixed that we were able to make the push notification.

jsonsolanki commented 3 years ago

@meetme2meat Thanks for your replay. can you give me brief me or give example regarding which kind of header attributes ?

meetme2meat commented 3 years ago

@jsonsolanki Sorry I can't give you more detail around this since we(both the developer) working on the project have moved on to a different organization what I remember that my colleague who was working on frontend PJSIP.js was sending the header in the wrong format.

How did we figure that out?

Initially, we use a custom (nodejs) server (URL of which was defined in the flexisip) which flexisip would call in the event of Push notification (or when it has to send a push notification).

At first, we saw flexisip-pusher working (i.e flexsip was sending a request to our server every time we would originate an event from flexisip-pusher service)

We capture the SIP packet (using tcpdump) on flexisip server.

Then my colleague would try a token registration (or something like it) and we capture that SIP and then we compare both the SIP packet.

We came to the conclusion that we weren't sending the headers exactly as it was needed in flexisip. If my memory goes correctly we were sending token as URI params as oppose to contact URI (I'm not 100% sure on this)

Once we started the custom server(and removed our Nodejs server) we use the default flexsip setting to sent the push notification.