Working with JSON logs from sudo in syslog-ng

This weekend I am going to give a talk about sudo in the security track of FOSDEM. I will talk a few words about logging at each major point I mention, but I cannot go into too much detail there. So, consider this blog both as a teaser and an extension to my FOSDEM talk. You will learn how to work with JSON formatted logs in syslog-ng and also about new sudo features along the way. You will also learn about JSON logging in sudo, chroot support, logging sub-commands, and how to work with these logs in syslog-ng.

Before you begin

You need up-to-date sudo and syslog-ng versions to use the features mentioned in this blog:

• JSON-formatted logs were introduced to sudo in version 1.9.4, but logging sub-commands became available only in version 1.9.8. Most Linux distributions still feature older versions. You can find sudo binaries for many platforms here: https://www.sudo.ws/getting/packages/

• On the syslog-ng side, I used version 3.35, the latest release at the time of writing this blog. Anything after 3.31 should work fine. Earlier versions lack the automatic parsing of @cee-flagged log messages. You might also need to install sub-packages for HTTP and JSON support. If your OS bundles an earlier syslog-ng version, you can find pointers to up-to-date packages for many platforms here: https://www.syslog-ng.com/products/open-source-log-management/3rd-party-binaries.aspx

Configuring sudo

You can configure sudo using the visudo command, which opens the sudoers file in the editor of your choice, and does a few checks before saving modifications. We append three lines to the end of the sudoers file:

Defaults log_format=json
Defaults log_subcmds
Defaults:%wheel runchroot=*

The first line enables JSON formatted log messages. The next one enables logging sub-commands. Finally, the last line enables chroot support for members of the wheel group. You can learn about these features more from my sudo blogs:

• JSON formatted logging: https://www.sudo.ws/posts/2020/12/sudo-1.9.4-new-options-for-logging/

• Logging sub-commands: https://www.sudo.ws/posts/2021/08/what-is-coming-in-sudo-1.9.8/

• chroot support: https://www.sudo.ws/posts/2020/09/using-chroot-and-cwd-in-sudo/

Before configuring syslog-ng, let’s check the logs. Before enabling JSON formatted logging in sudo, starting a shell using sudo -s looked like this:

Jan 28 13:56:27 localhost.localdomain sudo[10419]:   czanik : TTY=pts/0 ; PWD=/home/czanik ; USER=root ; COMMAND=/bin/bash

However, once we enabled JSON formatted logging, we get a lot more information. And not just a lot more, but also in a structured format which is easy to parse:

Jan 28 13:58:20 localhost.localdomain sudo[10518]: @cee:{"sudo":{"accept":{"uuid":"616bc9efcf-b239-469d-60ee-deb5af8ce6","server_time":{"seconds":1643374700,"nanoseconds":222446715,"iso8601":"20220128125820Z","localtime":"Jan 28 13:58:20"},"submit_time":{"seconds":1643374700,"nanoseconds":209935349,"iso8601":"20220128125820Z","localtime":"Jan 28 13:58:20"},"submituser":"czanik","command":"/bin/bash","runuser":"root","runcwd":"/home/czanik","ttyname":"/dev/pts/0","submithost":"localhost.localdomain","submitcwd":"/home/czanik","runuid":0,"columns":118,"lines":60,"runargv":["/bin/bash"],"runenv":["LANG=en_US.UTF-8","HOSTNAME=localhost.localdomain","SHELL=/bin/bash","TERM=xterm-256color","PATH=/home/czanik/.local/bin:/home/czanik/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin","MAIL=/var/mail/root","LOGNAME=root","USER=root","HOME=/root","SUDO_COMMAND=/bin/bash","SUDO_USER=czanik","SUDO_UID=1000","SUDO_GID=1000"]}}}

Configuring syslog-ng

Logs from sudo have been automatically parsed by syslog-ng for quite some time. Once JSON formatted logging was added to sudo, syslog-ng was also modified to parse JSON formatted logs marked with @cee out of box. This feature was added in syslog-ng version 3.31.1, that is why I recommended this as minimum version. JSON parsing arrived a lot earlier to syslog-ng, but there you have to configure parsing manually.

If you have an earlier version (but still at least 3.10) and cannot upgrade for whatever reason, check my previous blog about JSON formatted sudo logs here: https://www.syslog-ng.com/community/b/blog/posts/parsing-sudo-json-logs-building-a-syslog-ng-configuration

First create a configuration, which filters sudo log messages and stores them into a separate log file. Append it to syslog-ng.conf or store it with a .conf extension under /etc/syslog-ng/conf.d/ if syslog-ng on your host is configured to use this directory:

filter f_sudo {
  program(sudo);
};
destination d_sudo {
  file("/var/log/sudo");
};
log {
  source(s_sys);
  filter(f_sudo);
  destination(d_sudo);
};

Note, that the name of the source might be different on your system. Check the beginning of syslog-ng.conf, you are looking for the source which contains the system() source driver.

Once you reloaded syslog-ng, try to run a command through sudo. You should see sudo log messages appearing in /var/log/sudo.

Now, that the filter is working, bring this one step further: use the parsed results in the logs. For simplicity, we do not try to rebuild a complete syslog message, just the JSON part. We use the JSON template function for that:

filter f_sudo {
  program(sudo);
};
destination d_sudo {
  file("/var/log/sudo" template("$(format-json --scope rfc5424 --scope dot-nv-pairs
        --rekey .* --shift 1 --scope nv-pairs --exclude MESSAGE --exclude .journal*)\n\n"));
};
log {
  source(s_sys);
  filter(f_sudo);
  destination(d_sudo);
};

Once you saved the configuration and reloaded syslog-ng, test sudo again. Here is a sample log message:

{"cee":{"sudo":{"accept":{"uuid":"e6da96eb4d-e494-4fa2-2270-f13d79969d","ttyname":"/dev/pts/0","submituser":"czanik","submithost":"localhost.localdomain","submitcwd":"/home/czanik","submit_time":{"seconds":"1643380947","nanoseconds":"462682022","localtime":"Jan 28 15:42:27","iso8601":"20220128144227Z"},"server_time":{"seconds":"1643380947","nanoseconds":"477977979","localtime":"Jan 28 15:42:27","iso8601":"20220128144227Z"},"runuser":"root","runuid":"0","runenv[9]":"SUDO_COMMAND=/bin/bash","runenv[8]":"HOME=/root","runenv[7]":"USER=root","runenv[6]":"LOGNAME=root","runenv[5]":"MAIL=/var/mail/root","runenv[4]":"PATH=/home/czanik/.local/bin:/home/czanik/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin","runenv[3]":"TERM=xterm-256color","runenv[2]":"SHELL=/bin/bash","runenv[1]":"HOSTNAME=localhost.localdomain","runenv[12]":"SUDO_GID=1000","runenv[11]":"SUDO_UID=1000","runenv[10]":"SUDO_USER=czanik","runenv[0]":"LANG=en_US.UTF-8","runcwd":"/home/czanik","runargv[0]":"/bin/bash","lines":"60","command":"/bin/bash","columns":"118"}}},"app":{"name":"cee"},"SOURCE":"s_sys","PROGRAM":"sudo","PRIORITY":"notice","PID":"13575","HOST_FROM":"localhost","HOST":"localhost.localdomain","FACILITY":"authpriv","DATE":"Jan 28 15:42:27"}

As you can see, although we did not add any parser explicitly to the configuration, the JSON payload was still parsed and the template function created a log message which includes both syslog-related name value pars, and sudo-related fields. The parser is called on any log message arriving through the system() source.

The template function does a few extra tricks. By default, syslog-ng parses the JSON payload marked with @cee and saves everything under name-value pairs starting with a .cee prefix. The leading dot is replaced with an underscore in the JSON output, however that does not play nicely with Elasticsearch. So, we remove the leading dot from the names. And to prevent some redundancy, we also remove the original message and journal-related fields.

Alerting on chroot violations

Version 1.9.3 of sudo introduced chroot support. You can configure a fixed directory or a wildcard, where users are able to configure the target directory. There is a catch sudo --chroot / -s gives full root shell access, even if that was not the original intention. First, let’s check the log message for the above command:

{"cee":{"sudo":{"accept":{"uuid":"08324acc5d-353a-488b-cc6f-dc4c6e83e0","ttyname":"/dev/pts/0","submituser":"czanik","submithost":"localhost.localdomain","submitcwd":"/home/czanik","submit_time":{"seconds":"1643382369","nanoseconds":"161685861","localtime":"Jan 28 16:06:09","iso8601":"20220128150609Z"},"server_time":{"seconds":"1643382369","nanoseconds":"187055637","localtime":"Jan 28 16:06:09","iso8601":"20220128150609Z"},"runuser":"root","runuid":"0","runenv[9]":"SUDO_COMMAND=/bin/bash","runenv[8]":"HOME=/root","runenv[7]":"USER=root","runenv[6]":"LOGNAME=root","runenv[5]":"MAIL=/var/mail/root","runenv[4]":"PATH=/home/czanik/.local/bin:/home/czanik/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin","runenv[3]":"TERM=xterm-256color","runenv[2]":"SHELL=/bin/bash","runenv[1]":"HOSTNAME=localhost.localdomain","runenv[12]":"SUDO_GID=1000","runenv[11]":"SUDO_UID=1000","runenv[10]":"SUDO_USER=czanik","runenv[0]":"LANG=en_US.UTF-8","runcwd":"/home/czanik","runchroot":"/","runargv[0]":"/bin/bash","lines":"60","command":"/bin/bash","columns":"118"}}},"app":{"name":"cee"},"SOURCE":"s_sys","PROGRAM":"sudo","PRIORITY":"notice","PID":"14378","HOST_FROM":"localhost","HOST":"localhost.localdomain","FACILITY":"authpriv","DATE":"Jan 28 16:06:09"}

If you read it carefully, you will find that the value of the chroot option is stored in “runchroot”:”/”

The configuration below builds on the previous one but adds a filter to it which matches when this name-value pair refers to the root directory. Note that we use the leading dots here when referring to the names. Here the alert goes to a poorly formatted text file, but you can easily replace it with an alert to Slack or any other supported syslog-ng destinations.

filter f_sudo {
  program(sudo);
};
destination d_sudo {
  file("/var/log/sudo" template("$(format-json --scope rfc5424 --scope dot-nv-pairs
        --rekey .* --shift 1 --scope nv-pairs --exclude MESSAGE --exclude .journal*)\n\n"));
};
log {
  source(s_sys);
  filter(f_sudo);
  if (match("/" value(".cee.sudo.accept.runchroot"))) {
    destination { file("/var/log/sudo_danger" template("$(format-welf --key DATE --key .cee.sudo.accept.submituser)\n")); };
    # ToDo: change to a slack or smtp destination
  };
  destination(d_sudo);
};

The resulting file contains just a user name and the time of the violation.

Checking on sub-commands

Without logging sub-commands, all you see when a user starts a shell through sudo is a single line about starting the shell. However, hen you enable logging sub-commands in sudo, you will suddenly start to see what users are doing in a shell session initiated through sudo, or if they start external commands while editing a file through sudo. Without JSON formatting, you can recognize sub-commands from seeing many sudo log messages with the very same process id in the logs.

As usual, JSON formatted logs give you a lot more information and thus, finding sub-commands is also easier. Here are two log messages. The first one is the command started directly through sudo, the second one is executed within the shell I started:

{"cee":{"sudo":{"accept":{"uuid":"be17d7da37-3c6d-4cb8-38c1-11a771e0aa","ttyname":"/dev/pts/0","submituser":"czanik","
submithost":"localhost.localdomain","submitcwd":"/home/czanik","submit_time":{"seconds":"1643385098","nanoseconds":"32
9198052","localtime":"Jan 28 16:51:38","iso8601":"20220128155138Z"},"server_time":{"seconds":"1643385098","nanoseconds
":"352045133","localtime":"Jan 28 16:51:38","iso8601":"20220128155138Z"},"runuser":"root","runuid":"0","runenv[9]":"SU
DO_COMMAND=/bin/bash","runenv[8]":"HOME=/root","runenv[7]":"USER=root","runenv[6]":"LOGNAME=root","runenv[5]":"MAIL=/v
ar/mail/root","runenv[4]":"PATH=/home/czanik/.local/bin:/home/czanik/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/
sbin","runenv[3]":"TERM=xterm-256color","runenv[2]":"SHELL=/bin/bash","runenv[1]":"HOSTNAME=localhost.localdomain","ru
nenv[12]":"SUDO_GID=1000","runenv[11]":"SUDO_UID=1000","runenv[10]":"SUDO_USER=czanik","runenv[0]":"LANG=en_US.UTF-8",
"runcwd":"/home/czanik","runargv[0]":"/bin/bash","lines":"60","command":"/bin/bash","columns":"118"}}},"app":{"name":"
cee"},"SOURCE":"s_sys","PROGRAM":"sudo","PRIORITY":"notice","PID":"15392","HOST_FROM":"localhost","HOST":"localhost.lo
caldomain","FACILITY":"authpriv","DATE":"Jan 28 16:51:38"}

{"cee":{"sudo":{"accept":{"uuid":"be17d7da37-3c6d-4cb8-38c1-11a771e0aa","ttyname":"/dev/pts/0","submituser":"czanik","submithost":"localhost.localdomain","submitcwd":"/home/czanik","submit_time":{"seconds":"1643385098","nanoseconds":"329198052","localtime":"Jan 28 16:51:38","iso8601":"20220128155138Z"},"server_time":{"seconds":"1643385099","nanoseconds":"494292042","localtime":"Jan 28 16:51:39","iso8601":"20220128155139Z"},"runuser":"root","runuid":"0","runenv[9]":"SUDO_USER=czanik","runenv[8]":"HOME=/root","runenv[7]":"SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass","runenv[6]":"PWD=/home/czanik","runenv[5]":"USER=root","runenv[4]":"which_declare=declare -f","runenv[3]":"SUDO_COMMAND=/bin/bash","runenv[2]":"HOSTNAME=localhost.localdomain","runenv[22]":"_=/usr/bin/ls","runenv[21]":"BASH_FUNC_which%%=() {  ( alias;\n eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@\n}","runenv[20]":"LESSOPEN=||/usr/bin/lesspipe.sh %s","runenv[1]":"SUDO_GID=1000","runenv[19]":"LD_PRELOAD=/usr/libexec/sudo/sudo_intercept.so","runenv[18]":"PATH=/home/czanik/.local/bin:/home/czanik/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin","runenv[17]":"LOGNAME=root","runenv[16]":"SUDO_INTERCEPT_FD=18","runenv[15]":"SHLVL=1","runenv[14]":"SHELL=/bin/bash","runenv[13]":"TERM=xterm-256color","runenv[12]":"MAIL=/var/mail/root","runenv[11]":"SUDO_UID=1000","runenv[10]":"XDG_DATA_DIRS=/root/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share:/usr/share","runenv[0]":"LANG=en_US.UTF-8","runcwd":"/home/czanik","runargv[0]":"/usr/bin/ls","lines":"60","command":"/usr/bin/ls","columns":"118"}}},"app":{"name":"cee"},"SOURCE":"s_sys","PROGRAM":"sudo","PRIORITY":"notice","PID":"15392","HOST_FROM":"localhost","HOST":"localhost.localdomain","FACILITY":"authpriv","DATE":"Jan 28 16:51:39"}

From here, you have multiple ways to identify sub-commands. There is most likely a way also in syslog-ng to display them, but you will most likely analyze messages in Kibana or something similar. If you compare the first and the second messages, you can recognize a couple of differences. For example, in the second log, the content of SUDO_COMMAND and command are different: the first one points at Bash in both cases, while the second one points to the ls command in the second case. Also, only the second log shows that sudo_intercept.so is pre-loaded. And just like the process id, the uuid in the log is the same for logs belonging to the same session.

What is next?

Come to my FOSDEM talk to learn more details about the sudo side of the story: https://fosdem.org/2022/schedule/event/security_sudo/

-

If you have questions or comments related to syslog-ng, do not hesitate to contact us. You can reach us by email or even chat with us. For a list of possibilities, check our GitHub page under the “Community” section at https://github.com/syslog-ng/syslog-ng. On Twitter, I am available as @PCzanik.