BalaBit blog

GUARDING YOUR BUSINESS

Journal and syslog-ng

Saturday, February 4, 2012 @ 03:02 PM Author: Peter Czanik

The development version of my favorite Linux distribution, openSUSE just received an upgrade to systemd. This version includes the “journal”, the new logging framework for systemd. Here are my first experiences.

First of all, my testing environment: openSUSE factory snapshot from today with systemd 39 and syslog-ng 3.3.4:

linux-stu7:~ # syslog-ng -V
syslog-ng 3.3.4
Installer-Version: 3.3.4
Revision: ssh+git://bazsi@git.balabit//var/scm/git/syslog-ng/syslog-ng-ose--mainline--3.3#master#5e44eb46b0d7b86b62f17698e2b6de875ac8d7c6
Default-Modules: affile,afprog,afsocket,afuser,basicfuncs,csvparser,dbparser,syslogformat
Available-Modules: convertfuncs,afuser,basicfuncs,dbparser,confgen,syslogformat,dummy,afprog,csvparser,affile,afsocket,afmongodb
Enable-Debug: off
Enable-GProf: off
Enable-Memtrace: off
Enable-IPv6: on
Enable-Spoof-Source: on
Enable-TCP-Wrapper: on
Enable-Linux-Caps: on
Enable-Pcre: on

My first surprise came days before installation: I learned on the opensuse-factory mailing list, that rsyslog will still be installed by default. When I asked why, I was told, that those still using sysvinit need syslog installed on their systems. Of course it’s easy to workaround this problem by removing syslog from the default installation (which uses systemd) and add syslog as a dependency to the sysvinit-init package, which kicks off systemd-init.

As it turned out a few days later, when I installed Factory, my suggestion was accepted, but not yet implemented. What it means in practice, that logs are saved twice, both by the journal and syslog. So instead of making logging simpler, it adds additional complexity, storage requirement, etc. to the system.

Of course, as a syslog-ng guy, my first task was to remove rsyslog for the test machine and install syslog-ng instead :-) Unlike on a sysvinit system, replacing syslog is not a smooth process on systemd. After installation zypper reminds me to run “zypper ps” to see which running processes are using deleted files. And here comes the next surprise: it’s rsyslog. It’s not stopped and replaced by syslog-ng, as expected, but still there and running. Running “rcsyslog restart” (the openSUSE equivalent of /etc/init.d/syslog restart) does not fix the problem. Once I kill -9 rsyslog, it stops, but rcsyslog start still does not start, so I apply the good old Windows trick: reboot.

Update: no need to reboot, if systemctl deamon-reload is executed:

       daemon-reload
           Reload systemd manager configuration. This will reload all unit
           files and recreate the entire dependency tree. While the daemon is
           reloaded, all sockets systemd listens on on behalf of user
           configuration will stay accessible.

Once the test machine was rebooted, syslog-ng started just fine. Instead of opening /dev/log, as it is configured in syslog-ng.conf, it opened /run/systemd/journal/syslog, the new socket provided systemd for syslog compatibility. Messages appeared in the journal and were properly forwarded to syslog. Restarting syslog-ng worked also properly. (as a side note: rsyslog opened /dev/log, and part of the logs never reached the journal…)

Then came the next surprise. I tried “rcsyslog stop”, which I use occasionally when I know that a large amount of unnecessary logs is about to hit my syslog-ng server, or sometimes when I need to fsck my logging partition without shutting the machine down. It seems to me, that “stop” equals to “restart”, as syslog-ng was restarted immediately according to “ps aux” and logs. I called “kill -9” to the rescue, and syslog-ng was finally stopped, at least according to “ps aux”. “systemctl” gave a mixed answer:

 

linux-stu7:~ # systemctl status syslog.service
syslog.service - System Logging Service
      Loaded: loaded (/lib/systemd/system/syslog.service; enabled)
      Active: active (running) since Thu, 02 Feb 2012 13:24:50 +0100; 4min 51s ago
     Process: 5948 ExecStart=/sbin/syslog-ng (code=exited, status=0/SUCCESS)
     Process: 5946 ExecStartPre=/var/run/syslog-ng/addsockets (code=exited, status=0/SUCCESS)
     Process: 5944 ExecStartPre=/bin/systemctl stop systemd-kmsg-syslogd.service (code=exited, status=0/SUCCESS)
    Main PID: 5950 (code=killed, signal=KILL)
      CGroup: name=systemd:/system/syslog.service

So it’s “active (running)” and “exited/killed” at the same time :) Starting syslog-ng again with systemctl or rcsyslog did not work any more. Of course, starting syslog-ng from the command line works, but in this case syslog-ng uses the configured sockets. In my case it used /dev/log, kicking off systemd from it.

BTW: also checked rsyslog, these problems are not specific to syslog-ng

As I only tested systemd on openSUSE, I don’t know if these problems are systemd or openSUSE specific. But in either case, systemd/journal and syslog needs some work to be useful and not just complicate things:

  • when using systemd: no syslog by default, as it just makes all messages logged twice
  • make “rcsyslog start/stop”/”systemctl start/stop syslog.service” work under systemd
  • make a separate config for systemd, to avoid confusion with /dev/log (well, as syslog-ng package maintainer, I already have some ideas…)

If I have a little time next week, I plan to check it on Fedora Rawhide, or give Arch Linux a try to see, if problems are openSUSE related or more general. Based on my previous syslog-ng experiences on Fedora, I suspect the later.