Understanding contextual logs

When running on production serving million of users, it is unrealistic to run with a log verbosity level below warnings: it will too much affect the performance of the server, in terms of CPU and disk usage.

However, it may be desired to obtain debug logs for a limited subset of SIP messages being processed by Flexisip, in order for example to troubleshoot a calling issue affecting a particular user.

This is made possible thanks to contextual logs, which are controlled by two properties of Global section of flexisip.conf:

# A boolean expression applied to current SIP message being processed.
# When matched, logs are output provided that their level is greater
# than the value defined in contextual-log-level. The definition
# of the SIP boolean expression is the same as for entry filters
# of modules, which is documented here: https://wiki.linphone.org/xwiki/wiki/public/view/Flexisip/Configuration/Filter%20syntax/
#  Default value: 
contextual-log-filter=

# Verbosity of contextual logs to output when the condition defined
# in 'contextual-log-filter' is met.
#  Default value: debug
contextual-log-level=debug

The language used to define SIP boolean expression is fully documented here. Here are some examples to illustrate:

Enable debug logs for all activity related to a particular user 'alice':

contextual-log-filter=(from.uri.user == 'alice' || to.uri.user == 'alice')

Enable debug logs relative to the processing of SUBSCRIBE/NOTIFY requests:

contextual-log-filter=request.method == 'SUBSCRIBE || request.method == 'NOTIFY'

Enable debug logs relative to the processing of a 488 error response from a client:

contextual-log-filter=status.code == '488'

Activating contextual logs at run-time

Since troubleshooting could be necessary at any time on a production system, but restarting the service to have the configuration taking into effect is not an option, it is possible to dynamically change the values of the contextual-log-filter and contextual-log-level properties. The change is temporary: the flexisip.conf configuration file is not modified and after a restart the values from flexisip.conf will be used.

To change these values, use the flexisip-cli.py tool (included in flexisip packages in /opt/belledonne-communications/bin). In the following example, we setup a filter to enable logging of everything related to a REGISTER request coming from french phone numbers:

flexisip_cli.py -s proxy CONFIG_SET global/contextual-log-filter request.method == \'REGISTER\' '&&' \(from.uri.user contains \'+33\'\)

Pay attention to the escaping: indeed the shell is interpreting some of the operators used in flexisip's sip boolean expression language. In particular:

  • words enclosed by single quotes must have single quotes escaped by '\' character
  • operators like '&&', '||' must be surrounded by single quotes to avoid the shell interpreter to process them.
  • parenthesis must be preceded by '\' character.

To control that your sip boolean expression has correctly been passed to the server, flexisip_cli.py displays the expression that was interpreted by the flexisip server:

contextual-log-filter : request.method == 'REGISTER' && (from.uri.user contains '+33')

Known limitations

Only the proxy service supports contextual log filtering.

 

Tags:
Created by Simon Morlat on 2019/04/12 11:49