Smart Logging with OpenSIPS 3.4

The logging is an essential component of the operational side of SIP systems. The troubleshooting, the monitoring, the alarms and more do rely on logs. So the logs are essentials – and to address this, you need to have readable / understandable logs (as format and content).

Another challenge when comes to logs is their variety and distributed nature. A SIP system usually consists of several applications, each producing its own logs – and all these logs are to be digested by some common monitoring sub-system. So, ideally, we should have some common format for the logs, to help with reading and understanding the logs from all the applications we have. To make things even more complicated, a SIP system may be distributed, with components being clustered across different locations – so the logs must be easy to transport and aggregate.

All the above translates into couple of strong requirements when comes to the logs:

• they have to have a standard format(s) (like json, CEE)
• they have to be easy to transport/collect (using exiting transport mechanisms, like Kafka, RMQ)
• apps may log to different backends in the same time (like all logs to syslog, errors to RMQ).

Having all these in mind, we did a fundamental re-work of the logging support in OpenSIPS 3.4.

The Logging Interface

The new logging interface in OpenSIPS 3.4 is conceptually structured around a “Producer – Consumer” paradigm. OpenSIPS produces log messages as a result of its operation and several backends can “consume” those logs, a.k.a. deliver them with specific formatting and filtering to standard error, syslog or through OpenSIPS events, to other services.

In terms of implementation this is all encapsulated in the OpenSIPS core, although in case of using events to send logs, the actual event transport backends, which are separate OpenSIPS modules (eg. event_stream, event_kafka etc.), are also required.

Configuration and Settings

As a result of the new approach, the logging related settings and configurations now address the producer and each consumer separately. As such, core parameters such as log_level, xlog_level, log_pefix etc. or the log_level, xlog_level MI commands, control how OpenSIPS produces logs (the global/xlog verbosity, the log prefix etc.), same as before. On the other hand, each consumer now has specific parameters that control various settings, such as syslog_enabled, syslog_facility, syslog_log_format etc.

Logging via each consumer, can be enabled individually, via the stderror_enabled, syslog_enabled and log_event_enabled global parameters but can be also changed at runtime with the log_mute_state MI function.

Filtering of the log messages to be delivered via each consumer, by log level, can be achieved by setting the stderror_level_filter, syslog_level_filter and log_event_level_filter core parameters and can also be changed at runtime with the log_level_filter MI command. That means we can now, for example, print DEBUG level messages at standard error, while at the same time keep the syslog clean with only important logs like warnings and errors. For the previous example, we would need to set the following in the OpenSIPS config:

log_level=4

stderror_enabled=yes
syslog_enabled=yes

stderror_level_filter=4
syslog_level_filter=1

Going forward with the above example, we can after a while limit the volume of logs at standard error to only INFO level messages and above, with:

opensips-cli -x mi log_level_filter stderror 1

or even mute them altogether with:

opensips-cli -x mi log_mute_state stderror 1

Log Formats

OpenSIPS 3.4 introduces the possibility to print the logs in a JSON, structured format, for the standard error and syslog consumers, by setting the stderror_log_format and syslog_log_format global parameters. The are actually two schemas available for the JSON format:

• a basic, custom OpenSIPS schema, with log messages that look like, for example:
  
  {“time”: “Jun 13 19:09:54”, “pid”: 57437, “level”: “DBG”, “module”: “core”, “function”: “parse_to_param”, “message”: “tag=abcde\n”}
  
  
• the JSON CEE standard (1.0-beta1, documented here) with messages such as:
  
  {“time”: “Jun 13 19:09:54”, “proc”: {“id”: “57437”}, “pri”: “DBG”, “subsys”: “core”, “native”: {“function”: “parse_to_param”}, “msg”: “tag=abcde\n”, “pname”: “opensips”, “hostname”: “host1.example.org”}

Event Consumer

Enabling the event consumer will result in the triggering of the E_CORE_LOG event for each log message produced by OpenSIPS. This opens up numerous possibilities to send the logs to external services by using the event transport modules in OpenSIPS and subscribing to this new event exposed by the core. The formatting of such logs is thus handled by the event backend modules themselves, which usually pack the published messages as JSON-RPC notifications.

A very flexible approach for the event consumer, both in terms of formatting and available external integrations, is using the event_route module. This effectively allows you to do custom OpenSIPS scripting for publishing the log messages, with all of the relevant information (current time, PID, log level, the actual message payload etc.) available as event parameters.

Conclusions

The new 3.4 version brings major improvements to the logging abilities of OpenSIPS, such as structured JSON logging, multiple backends, better control of the log delivery and new integration capabilities with external services. Aggregating and analyzing logs can now be much easier in an ecosystem will multiple conforming applications.