Looking inside sudo shell sessions: auditd, session recordings, log_subcmds
There are situations where you cannot avoid giving a user full shell access through sudo. A shell with administrative privileges gives complete control over your hosts. Until recently, sudo could only log the start of the shell, not the commands executed within it. You could record sessions with sudo, but watching recordings is boring, time consuming and can still be subverted. Version 1.9.8 introduced logging of sub-commands, but that is not yet available on many systems. An alternate approach is to use auditd to log commands started from a root shell.
From this blog you will learn how to use auditd to log commands from a sudo-run root shell, why it is better to use the sub-command logging built into recent sudo releases, and why you should still record sessions with sudo.
Autitd is installed by default on most Linux systems, just like sudo. Unless you are running something really ancient, you should have at least sudo version 1.8 installed, which supports session recording. If you want to try logging sub-commands within sudo (and trust me, you do), you will need at least version 1.9.8 for that. This is available in some Linux distributions and BSD variants, but it is not yet ubiquitous. You can find the latest version compiled for many platforms at https://www.sudo.ws/getting/download/#binary.
For testing, I used CentOS 7. It has sudo 1.8 and auditd installed. First I appended the following two lines to /etc/audit/rules.d/audit.rules:
-a always,exit -F arch=b64 -S execve -F euid=0 -F auid>=1000 -F auid!=-1 -F key=subcom
-a always,exit -F arch=b32 -S execve -F euid=0 -F auid>=1000 -F auid!=-1 -F key=subcom
Then I restarted auditd to make sure that the changes take effect:
service auditd restart
The rules above will log command executions on both 32 and 64 bit systems when the effective user is root but the original user is greater than or equal to 1000 (the smallest UID for a regular user on most systems). Finally, we mark the log messages with “subcom” (short for sub-command) to make it easier to find the log entries.
Now when you start a shell using sudo and run a few commands, you will see everything listed in /var/log/auditd/auditd.log. This can be hard to read but the output of ausearch is (a little bit) simpler. It takes the username running sudo as a parameter:
ausearch -ua czanik
----
time->Wed May 25 14:32:34 2022
type=USER_ACCT msg=audit(1653481954.458:384): pid=18647 uid=1000 auid=1000 ses=5 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="czanik" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success'
----
time->Wed May 25 14:32:34 2022
type=USER_CMD msg=audit(1653481954.459:385): pid=18647 uid=1000 auid=1000 ses=5 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='cwd="/home/czanik" cmd="/bin/bash" terminal=pts/1 res=success'
----
time->Wed May 25 14:32:34 2022
type=CRED_REFR msg=audit(1653481954.459:386): pid=18647 uid=0 auid=1000 ses=5 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success'
----
time->Wed May 25 14:32:34 2022
type=USER_START msg=audit(1653481954.468:387): pid=18647 uid=0 auid=1000 ses=5 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_open grantors=pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success'
----
time->Wed May 25 14:32:34 2022
type=PROCTITLE msg=audit(1653481954.469:388): proctitle="/bin/bash"
type=PATH msg=audit(1653481954.469:388): item=1 name="/lib64/ld-linux-x86-64.so.2" inode=33184 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:ld_so_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=PATH msg=audit(1653481954.469:388): item=0 name="/bin/bash" inode=50333354 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:shell_exec_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=CWD msg=audit(1653481954.469:388): cwd="/home/czanik"
type=EXECVE msg=audit(1653481954.469:388): argc=1 a0="/bin/bash"
type=SYSCALL msg=audit(1653481954.469:388): arch=c000003e syscall=59 success=yes exit=0 a0=5620ac437228 a1=5620ac448ee8 a2=5620ac46d8c0 a3=0 items=2 ppid=18647 pid=18649 auid=1000 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 ses=5 comm="bash" exe="/usr/bin/bash" subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key="subcom"
----
time->Wed May 25 14:32:34 2022
type=PROCTITLE msg=audit(1653481954.472:389): proctitle=747479002D73
type=PATH msg=audit(1653481954.472:389): item=1 name="/lib64/ld-linux-x86-64.so.2" inode=33184 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:ld_so_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=PATH msg=audit(1653481954.472:389): item=0 name="/bin/tty" inode=52490149 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:bin_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=CWD msg=audit(1653481954.472:389): cwd="/home/czanik"
type=EXECVE msg=audit(1653481954.472:389): argc=2 a0="tty" a1="-s"
type=SYSCALL msg=audit(1653481954.472:389): arch=c000003e syscall=59 success=yes exit=0 a0=1283830 a1=1284800 a2=1282980 a3=7ffc87010020 items=2 ppid=18649 pid=18650 auid=1000 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 ses=5 comm="tty" exe="/usr/bin/tty" subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key="subcom"
----
[...]
----
time->Wed May 25 14:32:34 2022
type=PROCTITLE msg=audit(1653481954.594:407): proctitle=2F7573722F62696E2F6964002D75
type=PATH msg=audit(1653481954.594:407): item=1 name="/lib64/ld-linux-x86-64.so.2" inode=33184 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:ld_so_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=PATH msg=audit(1653481954.594:407): item=0 name="/usr/bin/id" inode=50407098 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:bin_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=CWD msg=audit(1653481954.594:407): cwd="/home/czanik"
type=EXECVE msg=audit(1653481954.594:407): argc=2 a0="/usr/bin/id" a1="-u"
type=SYSCALL msg=audit(1653481954.594:407): arch=c000003e syscall=59 success=yes exit=0 a0=12f8620 a1=1311d70 a2=1277440 a3=7ffc8700f6e0 items=2 ppid=18681 pid=18682 auid=1000 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 ses=5 comm="id" exe="/usr/bin/id" subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key="subcom"
----
time->Wed May 25 14:32:39 2022
type=PROCTITLE msg=audit(1653481959.289:408): proctitle=636174002F6574632F706173737764
type=PATH msg=audit(1653481959.289:408): item=1 name="/lib64/ld-linux-x86-64.so.2" inode=33184 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:ld_so_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=PATH msg=audit(1653481959.289:408): item=0 name="/bin/cat" inode=50334420 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:bin_t:s0 objtype=NORMAL cap_fp=0000000000000000 cap_fi=0000000000000000 cap_fe=0 cap_fver=0
type=CWD msg=audit(1653481959.289:408): cwd="/home/czanik"
type=EXECVE msg=audit(1653481959.289:408): argc=2 a0="cat" a1="/etc/passwd"
type=SYSCALL msg=audit(1653481959.289:408): arch=c000003e syscall=59 success=yes exit=0 a0=12813b0 a1=13a3360 a2=1277440 a3=7ffc87011660 items=2 ppid=18649 pid=18687 auid=1000 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 ses=5 comm="cat" exe="/usr/bin/cat" subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key="subcom"
----
time->Wed May 25 14:32:41 2022
type=USER_END msg=audit(1653481961.054:409): pid=18647 uid=0 auid=1000 ses=5 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_close grantors=pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success'
----
time->Wed May 25 14:32:41 2022
type=CRED_DISP msg=audit(1653481961.055:410): pid=18647 uid=0 auid=1000 ses=5 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="root" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success'
This is a lot of information. I even discarded most of it (marked with […]). When starting bash, all of the commands executed from various profile scripts are logged in detail. Even when using ausearch, the logs are still difficult to read. Log messages are split to multiple lines, and there is no obvious connection between the log messages. If two people were running shell sessions through sudo, one could not determine easily which command was run by which user. Also, built-in shell commands are not detected.
With some limitations, sudo itself can also log sub-commands. It cannot log built-in commands of shells, commands run from static binaries, and a few other corner cases. However, logging works in most cases and produces much easier to use results than auditd. Best of all, you can use JSON formatting for the logs, which provides not just easier to parse results, but also a lot more information. You can turn logging of sub-commands and JSON formatting on using the following settings in the sudoers file:
Defaults log_subcmds
Defaults log_format=json
The example below does not use JSON formatting due to space considerations. These are logs about a text editor being started from sudo. When logging of sub-commands is not enabled, you can only see the first line from these logs: starting the editor. When logging of sub-commands is enabled, you can see that a shell is started from the editor, all the commands run from various profile files and the commands executed by the user:
Aug 30 13:13:14 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/joe
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/bin/sh -c /bin/bash
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/bin/bash
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/readlink /proc/10889/exe
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/dircolors -b /etc/DIR_COLORS
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/tput hs
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/tput -T dumb+sl hs
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/tput bold
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/tput setaf 1
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/tput sgr0
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/sbin/ip --color=auto -V
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/readlink /proc/10889/exe
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/tty
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/uname -m
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/bin/uname -n
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/bin/uname -m
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/manpath -q
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/flatpak --installations
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/cat /etc/sysconfig/mpi-selector
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/sed -r s@/*:|([^\\]):@\1\n@g;H;x;s@/\n@\n@
Aug 30 13:13:37 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/tty
Aug 30 13:13:42 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/id
Aug 30 13:13:56 czplaptop sudo[10874]: czanik : TTY=pts/1 ; PWD=/home/czanik ; USER=root ; COMMAND=/usr/bin/ls -A -N --color=none -T 0 /usr/share/syslog-ng/include/scl/
You can easily spot log messages belonging to the same sudo session or executed by the same user. The process ID of sudo or the user name connects these log messages together. If you change to JSON formatted logging, you can see a lot more detailed information, including environment variables, which can explain the strange behavior of some applications.
You can read more about logging sub-commands in one of my earlier blogs at https://www.sudo.ws/posts/2021/08/what-is-coming-in-sudo-1.9.8/
As I mentioned in the introduction, it is easier to browse logs than to watch lengthy session recordings. Watching recordings also doesn’t show the (possibly malicious) commands started automatically from profile files. However, there are situations where simply reading the log messages does not explain exactly what happened on your system. This is where session recordings can come in handy.
Watching session recordings you can see everything that a user did in a sudo session. For example, you can see if a user deleted files using Midnight Commander. You can also enable keystroke recording and check what the user entered even when commands are not echoed on the terminal. It is also possible to see built-in commands running.
By default, sudo session recordings are saved locally when enabled with:
Defaults log_input, log_output
As logging keystrokes can result in some privacy problems (like logging passwords), you need to enable it separately. Terminal output can be played back using the sudoreplay command. There is no dedicated utility to view the terminal input, but it is stored in plaintext as a compressed file.
Sudo can also send session recordings to a central location: https://www.sudo.ws/posts/2020/03/whats-new-in-sudo-1.9-recording-service/.
Version 1.9.10 enables hiding passwords in session recordings: https://www.sudo.ws/posts/2022/03/sudo-1.9.10-hiding-passwords-in-session-recordings/ .
Some best practices:
-
To see inside shell (or editor) sessions, enable logging of sub-commands.
-
If using sudo < 1.9.8, auditd can be used as a workaround.
-
Use traditional sudo logs if saving to text files, but use JSON formatting if you store sudo logs to Elasticsearch or other services that can parse JSON. It contains a lot more useful information in an easy to parse format.
-
Collect session recordings, as in some corner cases it can reveal information that cannot be logged to traditional log files.
If you would like to be notified about new posts and sudo news, sign up for the sudo blog announcement mailing list.