RFC: Unified and structured logging

Development RFCs
1

http://projects.theforeman.org/issues/22569

This effort aims to solve three problems: enriching logging information with context to improve filtering, adding possibility to transfer logs over network (Smart Proxy to Foreman server, Capsule to Satellite etc) and enabling integration with 3rd party logging systems (ELK, systemd, rsyslog, syslog-ng) for easier maintenance.

Currently we are using simple file appenders (production.log, proxy.log). The goal is to use system logging daemon which provides better control (configuration, throttling, alerting, filtering) and log rotation. The best fit for the future is to use native systemd-journald daemon for easy structured logging in foreman core and smart-proxy, backend systems can either use system journal or syslog as a fallback mechanism.

The journald version in RHEL 7.4 (219) is stable and capable enough for all we need, including logs transfer via systemd-journal-gateway which provides SSL secured HTTPS endpoint for remote logs download. System journal is enabled by default on all supported OSes (RHEL, Fedora, Debian/Ubuntu), in the default configuration on RHEL passes data into rsyslog effectively dropping all structured logging but users will be able to change that to leverage all features of system journal (e.g. filter logs by additional flags).

For best benefit of both journald and rsyslog users, in the default configuration Foreman and Proxy will log all data with extra fields but also include the most important fields in log lines in human-readable format for easy grepping. System journal users can still filter logs via native journald utilities while traditional log service users can also correlate data manually via grep.

Users will be able to configure Foreman also with syslog and traditional file appending and rotation when necessary. For this, we will add puppet variables and installer options to support that. Further integration will be possible via 3rd party plugins (ELK) that can pull information from systemd directly via systemd-journal-gateway or via rsyslog which has module to send data into Elasticsearch directly (omelasticsearch). Installer will have options to configure JSON output, but further manual configuration will be needed to get full integration.

Container environment is also important deployment type for the future, in OpenShift v3 environment it is recommended to have all logging on standard output in JSON notation. This is a feature of logging gem, it offers JSON formatter out of box and this will be supported, so Foreman logging stack will be prepared for the future.

The key concept is to have sane default, so users still see all log entries in traditional production.log in human-readable form but after few configuration changes, they can start using structured logging via system journal or grab logs into ELK.

1 Like
2

The plan is currently:

To fully leverage syslog filtering (ability to file entries into individual files like production.log or candlepin.log) and output module plugins or scripts (omfile or omprog), we will use local syslog facilities in the following way:

  • local0: unused
  • local1: unused
  • local2: unused
  • local3: unused
  • local4: candlepin logs (omfile candlepin.log)
  • local5: smart proxy logs (omfile proxy.log)
  • local6: foreman core and dynflow/tasks logs (omfile production.log)
  • local7: reserved for boot logs
1 Like
3

In few installer changes, the plan is to have journal/syslog enabled by default and dropping a file that will cause all entries to be logged under the original location to avoid confusion after upgrade:

# cat /etc/rsyslog.d/foreman.conf
local6.* /var/log/foreman/production.log

There is a question how to do that in our puppet installer - @ekohl mentioned that this would mean starting managing syslog daemon (rsyslog or syslog-ng depending on user preference in Devian, for EL7 it’s just rsyslog). I don’t know how to approach this, I’d like just to have the configuration to be dropped, but puppet experts need to discuss here, thanks.

4

FIrst off, this looks awesome @lzap. Kudos! I appreciate as a Katello developer the attention to ensuring Candlepin logs are sent off to the system log. I know the Pulp backend is already sending logs to system log so that is covered. I wondered, should we work with their communities to get structured logging support for full stack support?

You mentioned syslog filtering, and I see Candlepin in that list with it’s own facility. Does Pulp also need one?

Maybe more broadly you can speak to the list of services in (https://github.com/theforeman/hammer-cli-foreman-admin#logging) as to why or why not they should be include for helping those of us less familiar with logging to understand the line to draw.

Some of our operations, for example client operations or reverse proxy on a Foreman proxy with content, hit Apache which we currently configure to log to files. Is there any work we should look into around sending Apache to system log and/or structured logging configuration?

Again, thanks for the work in this area!

1 Like
5

Yeah, I was thinking for the first phase instead insisting on native JSON logging, ability to configure log format line allows us to create our own pseudo-JSON logging which should work just fine. If we configure log line in all backend systems to something like:

pattern='{ "message": "%m", request="%req_id" }'

we should get there pretty quickly. Candlepin already supports this today (Candlepin - Logging in Candlepin) while I created a ticket for Pulp (Task #3372: Ability to configure logging pattern via config - Pulp).

I’d love to, but Pulp currently does not support configuring syslog facility, it’s harcoded in codebase. I created a ticket and this is out of table for first phase of our logging improval. I hope Pulp team picks this quick: Story #3288: Make syslog facility a configurable option - Pulp

There is however a possibility how to filter pulp logs without syslog facility set, it just needs advanced rsyslog script as a “hackish” workaround, so we will be able to have most relevant logs in syslog: [Pulp-list] Pulp Logging Documentation for rsyslogd Incorrect

I intentionally put Apache aside, because the project seems to be avoiding syslog/journal on purpose, I believe this has something to do with amount of logging Apache generates for bigger sites. System log/journal is supposed to hold important entries like warnings or errors while Apache access files are here to hold records - it is expected to have lots of data for recording purposes. It’s unfortunate that in Rails there is no way of disabling INFO level messages for requests which are successful - this is IMHO unnecessary noise. Rails devs insist on this including logging all parameters, which turned to be problem for package profile uploads (we have a hack in our codebase to filter that out).

Leaving Apache logs out of system log/journal does not mean that integration with ELK is not possible. There will need to be some kind of Logstash apache plugin that will read the logs offline.

6

It’s probably a good idea to create a foreman-logging subpackage (possibly even foreman-logging-{journald,syslog}) that ensures the needed gems are installed and bundler groups configured. That would match the existing pattern of bundler groups.

I’d prefer to make the structured logging opt-in by using the same defaults and file appenders we’ve always used. This way we avoid touching the system loggers (journald, rsyslog or syslog-ng) and avoid conflicts with existing logging that the user may have configured. It’s also less work.

To configure foreman logging we currently expose a hash which we could inspect and check if we need to install additional packages. Then we do need to figure out if the UX of passing in a hash is acceptable.

For other applications (proxy, candlepin, pulp) we can probably take similar approaches. I’m not sure about syslog and journald. First of all if we should manage them in the installer, secondly where to put it. Would we introduce a syslog module and configure the service that way?

7

Agree with the subpackage.

I don’t want us to touch syslog, I just want our installer to drop a configuration file and restart syslog. It’s just technical limitation of puppet, I assume, we need to figure it out. I don’t want to ship with weaker default configuration just because of our installer. Logging to journal + syslog has several advantages I already described above.

Alternatively, we can simply accept the fact that messages will go to /var/log/messages by default and ask users to drop syslog configuraion to have that on the original location. That’s not that bad, then we don’t need to play around with syslog in Puppet.

Why introducing syslog is such a problem? I am no expert, but we just need to add package ensurement, configuration file presence and service restart, do we? On Debian systems we need to do switch between rsyslog and syslog-ng. Syslog is always present anyway, what is the issue?