Troubleshooting
- Fetch the operation logs
- How to read Flexisip's log files
- Flexisp-proxy.log
- Available information on proxy starting
- Content of /etc/hosts
- Order of the Flexisip modules and message on their initialization
- Version of Mediastreamer (SDK version)
- Number of CPU threads
- Other debug info on Mediastreamer library initialization
- List of the network interfaces and their settings
- List of the host aliases
- Backend used for the registrar database
- Value of the internal transport
- Global TLS certificates/key location
- List of listening addresses and ports (listening transports)
- DoS Protection whitelist
- Trusted hosts while authentication
- Domains that are authorized to operate with the proxy (after authentication)
- Push notification clients creation
- Debug the flow of a request
- Available information on proxy starting
- Flexisip-conference.log
- Flexisp-proxy.log
- Common issues
Fetch the operation logs
By default, all the operation logs are in the directory /var/opt/belledonne-communications/logs/flexisip on the machine that hosts Flexisip. This directory may be changed by the parameter global/log-directory.
There is a plain text log file for each Flexisip service :
Service | Log name |
---|---|
SIP Proxy | flexisip-proxy.log |
Presence server | flexisip-presence.log |
Conference server (Group chat server) | flexisip-conference.log |
Registration event server | flexisip-regevent.log |
flexisip-proxy.log and flexisip-conference.log are enough for the great majority of problems.
How to read Flexisip's log files
Flexisp-proxy.log
Available information on proxy starting
The last starting may be found by the searching the last occurrence of:
Here are some useful parts of the log on starting :
Content of /etc/hosts
2023-01-05 14:44:19:911 flexisip-debug-Read 127.0.0.1 localhost.localdomain
2023-01-05 14:44:19:911 flexisip-debug-Read 127.0.0.1 localhost4
2023-01-05 14:44:19:911 flexisip-debug-Read 127.0.0.1 localhost4.localdomain4
2023-01-05 14:44:19:911 flexisip-debug-Read ::1 localhost
2023-01-05 14:44:19:911 flexisip-debug-Read ::1 localhost.localdomain
2023-01-05 14:44:19:911 flexisip-debug-Read ::1 localhost6
2023-01-05 14:44:19:911 flexisip-debug-Read ::1 localhost6.localdomain6
Order of the Flexisip modules and message on their initialization
2023-01-05 14:44:19:912 flexisip-debug-BasicThreadPool [0xd42ce0]: init with 1 threads and queue size 1000
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [SanityChecker].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [GarbageIn].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [NatHelper].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [Authentication].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [Redirect].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [RegEvent].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [B2bua].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [GatewayAdapter].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [Presence].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [Registrar].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [StatisticsCollector].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [ContactRouteInserter].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [Router].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [PushNotification].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [LoadBalancer].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [MediaRelay].
2023-01-05 14:44:19:912 flexisip-message-Creating module instance of [Transcoder].
[…]
2023-01-05 14:44:19:915 flexisip-message-Creating module instance of [Forward].
Version of Mediastreamer (SDK version)
Number of CPU threads
Other debug info on Mediastreamer library initialization
2023-01-05 14:44:19:912 mediastreamer-message-srtp init
2023-01-05 14:44:19:915 mediastreamer-message-Registering all soundcard handlers
2023-01-05 14:44:19:915 mediastreamer-message-Registering all webcam handlers
2023-01-05 14:44:19:915 mediastreamer-message-Webcam StaticImage: Static picture added
2023-01-05 14:44:19:915 mediastreamer-message-ms_factory_init_voip() done
2023-01-05 14:44:19:915 mediastreamer-message-Loading ms plugins from [/opt/belledonne-communications/lib64/mediastreamer/plugins]
2023-01-05 14:44:19:915 mediastreamer-message-Cannot open directory /opt/belledonne-communications/lib64/mediastreamer/plugins: No such file or directory
List of the network interfaces and their settings
2023-01-05 14:44:19:921 flexisip-debug-New network: Name: ens192 Address: 51.255.123.123 Mask: 255.255.255.255
2023-01-05 14:44:19:921 flexisip-debug-New network: Name: lo Address: ::1 Mask: ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff
2023-01-05 14:44:19:921 flexisip-debug-New network: Name: ens192 Address: 2001:41d0:403:2767::1234 Mask: ffff:ffff:ffff:ffff::
2023-01-05 14:44:19:922 flexisip-debug-New network: Name: ens192 Address: fe80::250:56ff:fe06:95ee%ens192 Mask: ffff:ffff:ffff:ffff::
List of the host aliases
List of the aliases that have been given by global/aliases parameter.
2023-01-05 14:44:19:923 flexisip-debug-sip.linphone.org
2023-01-05 14:44:19:923 flexisip-debug-sip.linhome.org
2023-01-05 14:44:19:923 flexisip-debug-sip8.linhome.org
Backend used for the registrar database
See module::Registrar/db-implementation.
2023-01-05 14:44:19:923 flexisip-debug-Connecting to Redis server tcp://localhost:6379
2023-01-05 14:44:19:923 flexisip-debug-Creating main Redis connection
2023-01-05 14:44:19:924 flexisip-debug-Creating subscription Redis connection
2023-01-05 14:44:19:924 flexisip-debug-Authenticating to Redis server
Value of the internal transport
See cluster/internal-transport.
Global TLS certificates/key location
List of listening addresses and ports (listening transports)
2023-01-05 14:44:20:109 flexisip-debug- sip:51.xxx.xxx.xxx:5060;transport=udp;maddr=51.xxx.xxx.xxx
2023-01-05 14:44:20:109 flexisip-debug- sip:51.xxx.xxx.xxx:5060;transport=tcp;maddr=51.xxx.xxx.xxx
2023-01-05 14:44:20:109 flexisip-debug- sip:[2001:xxxx:xxx:xxxx::1234]:5060;transport=udp;maddr=[2001:xxxx:xxx:xxxx::1234]
2023-01-05 14:44:20:109 flexisip-debug- sip:[2001:xxxx:xxx:xxxx::1234]:5060;transport=tcp;maddr=[2001:xxxx:xxx:xxxx::1234]
2023-01-05 14:44:20:109 flexisip-debug- sip:127.0.0.1:5060;transport=udp;maddr=127.0.0.1
2023-01-05 14:44:20:109 flexisip-debug- sip:127.0.0.1:5060;transport=tcp;maddr=127.0.0.1
2023-01-05 14:44:20:109 flexisip-debug- sip:[::1]:5060;transport=udp;maddr=[::1]
2023-01-05 14:44:20:109 flexisip-debug- sip:[::1]:5060;transport=tcp;maddr=[::1]
2023-01-05 14:44:20:109 flexisip-debug- sip:sip8.linphone.org:5061;transport=tls;maddr=[2001:xxxx:xxx:xxxx::1234]
2023-01-05 14:44:20:119 flexisip-debug- sip:sip8.linphone.org:5061;transport=tls;maddr=51.xxx.xxx.xxx
2023-01-05 14:44:20:132 flexisip-debug- sip:51.xxx.xxx.xxx:5228;transport=tcp;maddr=51.xxx.xxx.xxx
2023-01-05 14:44:20:132 flexisip-debug- sip:[2001:xxxx:xxx:xxxx::1234]:5228;transport=tcp;maddr=[2001:xxxx:xxx:xxxx::1234]
2023-01-05 14:44:20:132 flexisip-debug- sip:127.0.0.1:5228;transport=tcp;maddr=127.0.0.1
2023-01-05 14:44:20:132 flexisip-debug- sip:[::1]:5228;transport=tcp;maddr=[::1]
2023-01-05 14:44:20:132 flexisip-debug- sip:sip8.linphone.org:5223;transport=tls;maddr=[2001:xxxx:xxx:xxxx::1234]
2023-01-05 14:44:20:139 flexisip-debug- sip:sip8.linphone.org:5223;transport=tls;maddr=51.xxx.xxx.xxx
2023-01-05 14:44:20:152 flexisip-debug- sip:51.xxx.xxx.xxx:5059;transport=tcp;maddr=51.xxx.xxx.xxx
DoS Protection whitelist
See module::DoSProtection/white-list.
2023-01-05 14:44:20:160 flexisip-message-Host 91.xxx.xxx.xxx is in DOS protection white list
2023-01-05 14:44:20:160 flexisip-message-Host 2001:xxxx:x:xxxx:: is in DOS protection white list
Trusted hosts while authentication
See module::Authentication/trusted-hosts.
2023-01-05 14:44:20:201 flexisip-message-IP [::1]:0 added to trusted hosts
2023-01-05 14:44:20:201 flexisip-message-IP [::ffff:5.xxx.xx.xxx]:0 added to trusted hosts
Domains that are authorized to operate with the proxy (after authentication)
See module::Authentication/auth-domains.
2023-01-05 14:44:20:202 flexisip-message-Found auth domain: sip.linhome.org
Push notification clients creation
Available information:
- Directory where APNS client certificates are placed in;
- Creation of each Apple client and the expiration date of the related APNS certificate;
- Creation of each Android/Firebase client and the related ProjectID;
- The TTL used for each Push Notification Request according the kind of event (call or instant message).
2023-01-05 14:44:47:150 flexisip-debug-AppleClient[0x26583a0]: constructing AppleClient
2023-01-05 14:44:47:152 flexisip-debug-Certificate /etc/flexisip/apn/org.linphone.phone.dev.pem has a valid expiration: Jun 23 08:57:28 2023 GMT.
2023-01-05 14:44:47:152 flexisip-debug-Http2Client[0x2658a60]: constructing Http2Client with TlsConnection[0x2658ca0]
2023-01-05 14:44:47:152 flexisip-debug-Adding ios push notification client [org.linphone.phone.dev]
2023-01-05 14:44:47:152 flexisip-debug-AppleClient[0x199f290]: constructing AppleClient
2023-01-05 14:44:47:153 flexisip-debug-Certificate /etc/flexisip/apn/org.linphone.phone.prod.pem has a valid expiration: Jun 23 08:57:28 2023 GMT.
2023-01-05 14:44:47:153 flexisip-debug-Http2Client[0x199fa30]: constructing Http2Client with TlsConnection[0x199ca90]
2023-01-05 14:44:47:153 flexisip-debug-Adding ios push notification client [org.linphone.phone.prod]
2023-01-05 14:44:47:153 flexisip-debug-AppleClient[0x2653ad0]: constructing AppleClient
2023-01-05 14:44:47:153 flexisip-debug-Certificate /etc/flexisip/apn/org.linphone.phone.voip.dev.pem has a valid expiration: Jun 23 08:57:28 2023 GMT.
2023-01-05 14:44:47:153 flexisip-debug-Http2Client[0x2654240]: constructing Http2Client with TlsConnection[0x2654480]
2023-01-05 14:44:47:153 flexisip-debug-Adding ios push notification client [org.linphone.phone.voip.dev]
2023-01-05 14:44:47:153 flexisip-debug-AppleClient[0x1d91e80]: constructing AppleClient
2023-01-05 14:44:47:154 flexisip-debug-Certificate /etc/flexisip/apn/org.linphone.phone.voip.prod.pem has a valid expiration: Jun 23 08:57:28 2023 GMT.
2023-01-05 14:44:47:154 flexisip-debug-Http2Client[0x1d926d0]: constructing Http2Client with TlsConnection[0x1d92910]
2023-01-05 14:44:47:154 flexisip-debug-Adding ios push notification client [org.linphone.phone.voip.prod]
2023-01-05 14:44:47:208 flexisip-debug-FirebaseClient[0x2689540]: constructing FirebaseClient
2023-01-05 14:44:47:208 flexisip-debug-Http2Client[0x2689300]: constructing Http2Client with TlsConnection[0x118a700]
2023-01-05 14:44:47:208 flexisip-debug-Adding firebase push notification client [92xxxxxxxxxx]
2023-01-05 14:44:47:209 flexisip-debug-PushNotification module loaded. Push ttl for calls is 50 seconds, and for IM 604800 seconds.
Debug the flow of a request
Each incoming/outgoing SIP message are systematically logged but without their body (excepted for call session INVITEs). So, you can easily follow the flow of a given request by searching for its Call-ID. For instance,
Received message:
2023-01-09 14:03:14:116 flexisip-debug-tport_recv_event(0xe77750)
2023-01-09 14:03:14:116 flexisip-debug-tport_recv_iovec(0xe77750) msg 0x2e52390 from (udp/51.xxx.xxx.xxx:5060) has 1841 bytes, veclen = 1
2023-01-09 14:03:14:116 flexisip-debug-tport_deliver(0xe77750): msg 0x2e52390 (1841 bytes) from udp/77.xxx.xx.xx:5060 next=(nil)
2023-01-09 14:03:14:116 flexisip-debug-nta: received INVITE sip:alice@sip.linphone.org:5060 SIP/2.0 (CSeq 21)
2023-01-09 14:03:14:116 flexisip-debug-nta: Via check: received=77.xxx.xx.xx
2023-01-09 14:03:14:116 flexisip-debug-nta: INVITE (21) to message callback
2023-01-09 14:03:14:116 flexisip-debug-New SipEvent 0x169b7630 - msg 0x2e52390
2023-01-09 14:03:14:116 flexisip-debug-Receiving new Request SIP message INVITE from sip:alice@sip.linphone.org :
INVITE sip:bob@sip.linphone.org:5060 SIP/2.0
Via: SIP/2.0/UDP 192.xxx.x.xxx:5060;branch=z9hG4bK.awUT5hrJB;rport=1024;received=77.xxx.xx.xx
From: <sip:alice@sip.linphone.org>;tag=T2WPeSsHv
To: sip:bob@sip.linphone.org
CSeq: 21 INVITE
Call-ID: FGwjp7bRfw
Max-Forwards: 70
Supported: replaces, outbound
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
Content-Type: application/sdp
Content-Length: 920
Contact: <sip:alice@77.xxx.xx.xx:1024>;+sip.instance="<urn:uuid:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx>"
User-Agent: Unknown (belle-sip/1.4.2)
Proxy-Authorization: Digest realm="sip.linphone.org", nonce="xxxxxx", algorithm=MD5, opaque="+GNywA==", username="xxxxxx", uri="sip:alice@sip.linphone.org:5060", response="xxxxxx", cnonce="xxxxxx", nc=00000001, qop=auth
[…]
Forwarded message:
INVITE sip:bob@77.129.18.79:42546;transport=tls SIP/2.0
Record-Route: <sips:sip8.linphone.org:5223;lr>
Record-Route: <sip:51.xxx.xxx.xxx:5060;lr>
Via: SIP/2.0/UDP 192.xxx.x.xxx:5060;branch=z9hG4bK.awUT5hrJB;rport=1024;received=77.xxx.xx.xx
Max-Forwards: 69
From: <sip:alice@sip.linphone.org>;tag=T2WPeSsHv
To: sip:bob@sip.linphone.org
Call-ID: FGwjp7bRfw
CSeq: 21 INVITE
Contact: <sip:alice@77.xxx.xx.xx:1024>;+sip.instance="<urn:uuid:xxxxxxxx-xxxx-xxxx-xxxxxxxxxxxx>"
User-Agent: Unknown (belle-sip/1.4.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
Supported: replaces, outbound
Content-Type: application/sdp
Content-Length: 940
[…]
2023-01-09 14:03:14:118 flexisip-debug-Message is sent through an outgoing transaction.
2023-01-09 14:03:14:118 flexisip-debug-tport_tsend(0x1d4cd2a0) tpn = tls/77.xxx.xx.xx:42546
2023-01-09 14:03:14:118 flexisip-debug-tport_tls_writevec: vec 0x757c9b0 0x193b3c0 844 (844)
2023-01-09 14:03:14:118 flexisip-debug-tport_tls_writevec: vec 0x757c9b0 0xd14ef40 940 (940)
2023-01-09 14:03:14:118 flexisip-debug-tport_vsend returned 1784
While an incoming request is processed by Flexisip, it goes through a chain of modules that may do the following action on the request:
- Add/remove/alter the headers of the message;
- Pass the request to the next module;
- Suspend the request, which cause the Flexisip to process another incoming request;
- Reply to the request with a terminal SIP response; the request won't go through the next modules.
Flexisip suspends a request when it is waiting for the result of an asynchronous operation (for example the response of a SQL request) to find out which action to do on the request.
Example of request processing:
Via: SIP/2.0/UDP 192.xxx.x.xxx:5060;branch=z9hG4bK.awUT5hrJB;rport=1024;received=77.xxx.xx.xx
From: <sip:alice@sip.linphone.org>;tag=T2WPeSsHv
To: sip:bob@sip.linphone.org
CSeq: 21 INVITE
Call-ID: FGwjp7bRfw
Max-Forwards: 70
Supported: replaces, outbound
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
Content-Type: application/sdp
Content-Length: 920
Contact: <sip:alice@77.xxx.xx.xx:1024>;+sip.instance="<urn:uuid:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx>"
User-Agent: Unknown (belle-sip/1.4.2)
Proxy-Authorization: Digest realm="sip.linphone.org", nonce="xxxxxx", algorithm=MD5, opaque="+GNywA==", username="xxxxxx", uri="sip:alice@sip.linphone.org:5060", response="xxxxxx", cnonce="xxxxxx", nc=00000001, qop=auth
[…]
2023-01-09 14:03:14:116 flexisip-debug-Invoking onRequest() on module DoSProtection
2023-01-09 14:03:14:116 flexisip-debug-Invoking onRequest() on module SanityChecker
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module GarbageIn
2023-01-09 14:03:14:116 flexisip-debug-Invoking onRequest() on module NatHelper
2023-01-09 14:03:14:116 flexisip-debug-Record route added.
2023-01-09 14:03:14:116 flexisip-debug-Invoking onRequest() on module Authentication
2023-01-09 14:03:14:116 flexisip-debug-New IncomingTransaction 0x17eace80
2023-01-09 14:03:14:116 flexisip-debug-nta_incoming_create: created incoming transaction 0x159f5900
2023-01-09 14:03:14:116 flexisip-debug-start digest authentication
2023-01-09 14:03:14:116 flexisip-debug-New FlexisipAuthStatus [0x8ad0e20]
2023-01-09 14:03:14:116 flexisip-debug-AuthStatus[0x8ad0e20]: 'sip.linphone.org' will be used as realm
2023-01-09 14:03:14:116 flexisip-debug-AuthStatus[0x8ad0e20]: searching for auth digest response for this proxy
2023-01-09 14:03:14:116 flexisip-debug-auth_digest_response_get: 12
2023-01-09 14:03:14:116 flexisip-debug-Examining auth digest response alice sip.linphone.org
2023-01-09 14:03:14:116 flexisip-debug-Expected realm found : sip.linphone.org
2023-01-09 14:03:14:116 flexisip-debug-auth_digest_response_get: 12
2023-01-09 14:03:14:116 flexisip-debug-AuthStatus[0x8ad0e20]: checking auth digest response for realm 'sip.linphone.org'
2023-01-09 14:03:14:116 flexisip-debug-Updating nonce Eo9m5wAAAAAnQPYOAACo/uw9zBsAAAAA with nc=1
2023-01-09 14:03:14:116 flexisip-debug-Suspend SipEvent 0x169b7630
2023-01-09 14:03:14:116 flexisip-debug-
==============================================================================================================
We see here that the request go through DoSProtection, SanityChecker, NetHelper and is suspended at the end of Authentication. The equal line means that Flexisip is changing context and is probably processing another request.
The processing of this request is resumed later in the log and suspended again while entering in the Router module:
2023-01-09 14:03:14:116 flexisip-debug-AuthStatus[0x8ad0e20]: password found for 'alice@sip.linphone.org', algorithms={ 'MD5', 'SHA-256' }
2023-01-09 14:03:14:116 flexisip-debug-A2 = MD5(INVITE:sip:alice@sip.linphone.org:5060)
2023-01-09 14:03:14:116 flexisip-debug-computeDigestResponse(): xxxxxx = MD5(xxxxxx:xxxxxx:00000001:xxxxxx:auth:xxxxxx) (qop=auth)
2023-01-09 14:03:14:116 flexisip-debug-AuthStatus[0x8ad0e20]: successful authentication
2023-01-09 14:03:14:116 flexisip-debug-auth_digest_response_get: 12
2023-01-09 14:03:14:116 flexisip-debug-Examining auth digest response alice sip.linphone.org
2023-01-09 14:03:14:116 flexisip-debug-Expected realm found : sip.linphone.org
2023-01-09 14:03:14:116 flexisip-debug-Inject request SIP event [0x169b7630] after Authentication:
INVITE sip:alice@sip.linphone.org:5060 SIP/2.0
Via: SIP/2.0/UDP 192.xxx.x.xxx:5060;branch=z9hG4bK.awUT5hrJB;rport=1024;received=77.xxx.xx.xx
From: <sip:alice@sip.linphone.org>;tag=T2WPeSsHv
To: sip:bob@sip.linphone.org
CSeq: 21 INVITE
Call-ID: FGwjp7bRfw
Max-Forwards: 70
Supported: replaces, outbound
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
Content-Type: application/sdp
Content-Length: 920
Contact: <sip:alice@77.xxx.xx.xx:1024>;+sip.instance="<urn:uuid:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx>"
User-Agent: Unknown (belle-sip/1.4.2)
Record-Route: <sip:51.xxx.xxx.xxx:5060;lr>
[…]
2023-01-09 14:03:14:116 flexisip-debug-Restart SipEvent 0x169b7630
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module Redirect
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module RegEvent
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module B2bua
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module GatewayAdapter
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module Presence
2023-01-09 14:03:14:116 flexisip-debug-Invoking onRequest() on module Registrar
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module StatisticsCollector
2023-01-09 14:03:14:116 flexisip-debug-Skipping onRequest() on module ContactRouteInserter
2023-01-09 14:03:14:116 flexisip-debug-Invoking onRequest() on module Router
2023-01-09 14:03:14:116 flexisip-debug-Fetch for url sip:bob@sip.linphone.org:5060.
2023-01-09 14:03:14:116 flexisip-debug-Replying Request SIP message: 100 Trying
2023-01-09 14:03:14:116 flexisip-debug-tport_tsend(0xe77750) tpn = UDP/77.xxx.xx.xx:1024
2023-01-09 14:03:14:116 flexisip-debug-tport_resolve addrinfo = 77.xxx.xx.xx:1024
2023-01-09 14:03:14:116 flexisip-debug-tport_by_addrinfo(0xe77750): not found by name UDP/77.xxx.xx.xx:1024
2023-01-09 14:03:14:116 flexisip-debug-tport_vsend returned 381
2023-01-09 14:03:14:116 flexisip-debug-nta: sent 100 Trying for INVITE (21)
2023-01-09 14:03:14:116 flexisip-debug-Suspend SipEvent 0x169b7630
2023-01-09 14:03:14:116 flexisip-debug-Fetching fs:bob@sip.linphone.org [0]
2023-01-09 14:03:14:116 flexisip-debug-
==============================================================================================================
Requests are finally forwarded while entering the Forward module, which is the last one in the chain.
Flexisip-conference.log
The SIP message flow may be easily followed by searching for the Call-ID of the message in the log.
Common issues
Push notifications not received by a SIP client
1. Check whether a Push Notification Request has been actually sent by the proxy
Use the Call-ID and the UUID of the recipient user agent to find the creation of the PNR.
Android/Firebase PNR creation:
{
"to":"xxxxxxxxxx",
"time_to_live": 50,
"priority":"high",
"data":{
"uuid":"<urn:uuid:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx>",
"from-uri":"sip:alice@sip.example.org",
"display-name":"Alice",
"call-id":"11-11-72CD0325-63BD29A900008351-D51D0700",
"sip-from":"Alice",
"loc-key":"",
"loc-args":"Alice",
"send-time":"2023-01-10 09:02:33"
}
}
Apple PNR creation:
{
"aps": {
"alert": {
"loc-key": "IM_MSG",
"loc-args": ["sip:alice@sip.linphone.org"]
},
"sound": "msg.caf",
"mutable-content": 1,
"badge": 1
},
"from-uri": "sip:alice@sip.example.org",
"display-name": "",
"call-id": "aOcJ3ckPh4",
"pn_ttl": 604800,
"uuid": "<urn:uuid:xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx>",
"send-time": "2023-01-10 09:03:10",
"chat-room-addr": "",
"customPayload": {}
}
Next, follow the state of the PNR by searching for its pointer, until you find this log:
If the final state is “Successful”, the PNR has successfully been sent and accepted by the Push Notification Server. So, the problem is located on client side.
If the final state is “Failed”, the PNR sending has failed. You should scroll a little back to examine the body of the HTTP/2 response to know the reason of the failure.
Instance of failing response to Apple PNR:
HttpMessage :
HttpMessage header :
:status = 410
apns-id = 9C1DF5E0-2C57-1A2A-C33B-876FE85A1E80
HttpMessage body :
{"reason":"Unregistered","timestamp":1669987414400}
2023-01-10 10:04:33:472 flexisip-debug-Request[0x1e558ea0]: switching state from InProgress -> Failed
2. iOS client: check the validity of the APNS client certificates
When you follow the PNR pointer, you may find this error message just after the request creation:
That means no PushClient has been created for the given “apns-topic”.
Get the “apns-topic“ in the HTTP/2 header just above the error message, org.example.myapp in this example:
:method = POST
:scheme = https
:path = /3/device/8796xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
apns-expiration = 1673949757
apns-topic = org.example.myapp
apns-push-type = alert
apns-priority = 10
2023-01-10 11:02:37:714 flexisip-error-No push notification client available for push notification request : 0x26925670
Then, check the push client creation part on flexisip-proxy starting (see Push notification clients creation above). If the apns-topic is not present, that means no certificate for this topic is present in /etc/flexisip/apns, you should check the expiration date otherwise.