Log systemd service state changes using rsyslog.

At first, look how the log entry looks like as it will come in handy in the next step.

$ sudo journalctl --follow --output verbose _TRANSPORT=journal SYSLOG_IDENTIFIER=systemd
Wed 2021-04-14 20:50:55.891441 UTC [s=9427351f18774a69b609ca7e9f914343;i=e2a;b=89d52c9da1f84b029e4f8270bec49e31;m=27bc63dbe5;t=5bff4e73b2823;x=7394e861da280911]
    _MACHINE_ID=8a3d7205b9ac458386ceba4c795decbb
    _HOSTNAME=bullseye
    PRIORITY=6
    SYSLOG_FACILITY=3
    SYSLOG_IDENTIFIER=systemd
    _UID=0
    _GID=0
    _SELINUX_CONTEXT=unconfined
    _TRANSPORT=journal
    _CAP_EFFECTIVE=1ffffffffff
    TID=1
    CODE_FILE=src/core/job.c
    JOB_TYPE=start
    _PID=1
    _COMM=systemd
    _EXE=/usr/lib/systemd/systemd
    _SYSTEMD_CGROUP=/init.scope
    _SYSTEMD_UNIT=init.scope
    _SYSTEMD_SLICE=-.slice
    CODE_LINE=940
    CODE_FUNC=job_log_done_status_message
    JOB_RESULT=done
    MESSAGE_ID=39f53479d3a045ac8e11786248231fbf
    UNIT=nginx.service
    MESSAGE=Started A high performance web server and a reverse proxy server.
    _BOOT_ID=89d52c9da1f84b029e4f8270bec49e31
    _CMDLINE=/lib/systemd/systemd --system --deserialize 35
    JOB_ID=2730
    INVOCATION_ID=ffd64fa6e3d744f5b18d76243c7dbde2
    _SOURCE_REALTIME_TIMESTAMP=1618433455891441

Create rsyslog configuration.

$ cat <<EOF | sudo tee /etc/rsyslog.d/systemd.conf
module(load="imjournal" IgnorePreviousMessages="on")
module(load="mmjsonparse")

template(name="systemd_message_template" type="string" string="%TIMESTAMP% %HOSTNAME% %programname%  %msg% [%\$!UNIT%, %\$!JOB_TYPE%, %\$!JOB_RESULT%, %\$!CODE_FUNC%]\n" )

action(type="mmjsonparse")
if \$programname == 'systemd' and \$!UNIT != "" then {
   action(type="omfile" file="/var/log/systemd_service_state.log" template="systemd_message_template")
}
EOF
module(load="imjournal" IgnorePreviousMessages="on")
module(load="mmjsonparse")

template(name="systemd_message_template" type="string" string="%TIMESTAMP% %HOSTNAME% %programname%  %msg% [%$!UNIT%, %$!JOB_TYPE%, %$!JOB_RESULT%, %$!CODE_FUNC%]\n" )

action(type="mmjsonparse")
if $programname == 'systemd' and $!UNIT != "" then {
   action(type="omfile" file="/var/log/systemd_service_state.log" template="systemd_message_template")
}

Test rsyslogd configuration.

$ sudo rsyslogd -N 1
rsyslogd: version 8.2102.0, config validation run (level 1), master config /etc/rsyslog.conf
rsyslogd: End of config validation run. Bye.

Restart rsyslogd service.

$ sudo systemctl restart rsyslog

This is how nginx restart operation is logged.

$ cat  /var/log/systemd_service_state.log
Apr 14 21:48:23 bullseye systemd  Stopping A high performance web server and a reverse proxy server... [nginx.service, stop, , job_log_begin_status_message]
Apr 14 21:48:23 bullseye systemd  nginx.service: Succeeded. [nginx.service, , , unit_log_success]
Apr 14 21:48:23 bullseye systemd  Stopped A high performance web server and a reverse proxy server. [nginx.service, restart, done, job_log_done_status_message]
Apr 14 21:48:23 bullseye systemd  Starting A high performance web server and a reverse proxy server... [nginx.service, start, , job_log_begin_status_message]
Apr 14 21:48:23 bullseye systemd  Started A high performance web server and a reverse proxy server. [nginx.service, start, done, job_log_done_status_message]

This is how system restart operation is logged.

$ cat /var/log/systemd_service_state.log
Apr 14 21:49:19 bullseye systemd  e2scrub_reap.service: Succeeded. [e2scrub_reap.service, , , unit_log_success]
Apr 14 21:49:19 bullseye systemd  Finished Remove Stale Online ext4 Metadata Check Snapshots. [e2scrub_reap.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Found device 82540EM Gigabit Ethernet Controller (PRO/1000 MT Desktop Adapter). [sys-subsystem-net-devices-eth0.device, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started ifup for eth0. [ifup@eth0.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started User Login Management. [systemd-logind.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Finished Helper to synchronize boot up for ifupdown. [ifupdown-pre.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Starting Raise network interfaces... [networking.service, start, , job_log_begin_status_message]
Apr 14 21:49:19 bullseye systemd  Finished Raise network interfaces. [networking.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Reached target Network. [network.target, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Starting chrony, an NTP client/server... [chrony.service, start, , job_log_begin_status_message]
Apr 14 21:49:19 bullseye systemd  Starting MariaDB 10.5.9 database server... [mariadb.service, start, , job_log_begin_status_message]
Apr 14 21:49:19 bullseye systemd  Starting A high performance web server and a reverse proxy server... [nginx.service, start, , job_log_begin_status_message]
Apr 14 21:49:19 bullseye systemd  Condition check resulted in fast remote file copy program daemon being skipped. [rsync.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Starting OpenBSD Secure Shell server... [ssh.service, start, , job_log_begin_status_message]
Apr 14 21:49:19 bullseye systemd  Starting Permit User Sessions... [systemd-user-sessions.service, start, , job_log_begin_status_message]
Apr 14 21:49:19 bullseye systemd  Started Unattended Upgrades Shutdown. [unattended-upgrades.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Finished Permit User Sessions. [systemd-user-sessions.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started Getty on tty1. [getty@tty1.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Reached target Login Prompts. [getty.target, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started OpenBSD Secure Shell server. [ssh.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started chrony, an NTP client/server. [chrony.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Reached target System Time Synchronized. [time-sync.target, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started Daily apt download activities. [apt-daily.timer, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started Daily apt upgrade and clean activities. [apt-daily-upgrade.timer, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started Periodic ext4 Online Metadata Check for All Filesystems. [e2scrub_all.timer, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started Discard unused blocks once a week. [fstrim.timer, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started Daily rotation of log files. [logrotate.timer, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started Daily man-db regeneration. [man-db.timer, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Reached target Timers. [timers.target, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  nginx.service: Failed to parse PID from file /run/nginx.pid: Invalid argument [nginx.service, , , service_load_pid_file]
Apr 14 21:49:19 bullseye systemd  Started A high performance web server and a reverse proxy server. [nginx.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Started MariaDB 10.5.9 database server. [mariadb.service, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Reached target Multi-User System. [multi-user.target, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Reached target Graphical Interface. [graphical.target, start, done, job_log_done_status_message]
Apr 14 21:49:19 bullseye systemd  Starting Update UTMP about System Runlevel Changes... [systemd-update-utmp-runlevel.service, start, , job_log_begin_status_message]
Apr 14 21:49:19 bullseye systemd  systemd-update-utmp-runlevel.service: Succeeded. [systemd-update-utmp-runlevel.service, , , unit_log_success]
Apr 14 21:49:19 bullseye systemd  Finished Update UTMP about System Runlevel Changes. [systemd-update-utmp-runlevel.service, start, done, job_log_done_status_message]
Apr 14 21:53:03 bullseye systemd  Created slice User Slice of UID 1000. [user-1000.slice, start, done, job_log_done_status_message]
Apr 14 21:53:03 bullseye systemd  Starting User Runtime Directory /run/user/1000... [user-runtime-dir@1000.service, start, , job_log_begin_status_message]
Apr 14 21:53:03 bullseye systemd  Finished User Runtime Directory /run/user/1000. [user-runtime-dir@1000.service, start, done, job_log_done_status_message]
Apr 14 21:53:03 bullseye systemd  Starting User Manager for UID 1000... [user@1000.service, start, , job_log_begin_status_message]
Apr 14 21:53:03 bullseye systemd  Started User Manager for UID 1000. [user@1000.service, start, done, job_log_done_status_message]
Apr 14 21:53:03 bullseye systemd  Started Session 1 of user vagrant. [session-1.scope, start, done, job_log_done_status_message]

See imjournal: Systemd Journal Input Module web-page for more information.