Page MenuHomeFreeBSD

periodic: Take syslog log format from RFC 5424 into account
Needs ReviewPublic

Authored by michaelo on Thu, Dec 25, 10:02 AM.
Tags
None
Referenced Files
Unknown Object (File)
Thu, Jan 8, 10:16 PM
Unknown Object (File)
Thu, Jan 8, 3:50 PM
Unknown Object (File)
Thu, Jan 8, 10:12 AM
Unknown Object (File)
Thu, Jan 8, 12:17 AM
Unknown Object (File)
Mon, Jan 5, 8:33 PM
Unknown Object (File)
Wed, Dec 31, 8:46 PM
Unknown Object (File)
Wed, Dec 31, 8:15 PM
Unknown Object (File)
Tue, Dec 30, 4:22 AM
Subscribers

Details

Reviewers
jrm
Summary

Make all scripts analyzing syslog output aware of the output format
based on the flags passed to syslogd. It is either BSD format (RFC 3164) or
newer RFC 5424.

PR: 270497
MFC after: 2 weeks

Diff Detail

Repository
rG FreeBSD src repository
Lint
Lint Skipped
Unit
Tests Skipped
Build Status
Buildable 69486
Build 66369: arc lint + arc unit

Event Timeline

Successfully arrived from last night:

deblndw011x.innomotics.net login failures:
<38>1 2025-12-24T10:04:50.770790+01:00 deblndw011x.innomotics.net sshd-session 13833 - - Invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 57514
<38>1 2025-12-24T10:04:50.863780+01:00 deblndw011x.innomotics.net sshd-session 13833 - - Postponed keyboard-interactive for invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 57514 ssh2 [preauth]
<35>1 2025-12-24T10:04:50.885123+01:00 deblndw011x.innomotics.net sshd-session 13833 - - error: PAM: Authentication error for illegal user uawet448@ad001.siemens.net from demchhc0dbx.hca.siemens.de
<38>1 2025-12-24T10:04:50.885602+01:00 deblndw011x.innomotics.net sshd-session 13833 - - Failed keyboard-interactive/pam for invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 57514 ssh2
<38>1 2025-12-24T10:04:50.911948+01:00 deblndw011x.innomotics.net sshd-session 13833 - - Failed password for invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 57514 ssh2
<38>1 2025-12-24T10:04:50.940358+01:00 deblndw011x.innomotics.net sshd-session 13833 - - Connection closed by invalid user uawet448@ad001.siemens.net 139.25.231.134 port 57514 [preauth]
<38>1 2025-12-24T10:04:51.244839+01:00 deblndw011x.innomotics.net sshd-session 13838 - - Invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 57556
<38>1 2025-12-24T10:04:51.646452+01:00 deblndw011x.innomotics.net sshd-session 13838 - - Postponed keyboard-interactive for invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 57556 ssh2 [preauth]
<35>1 2025-12-24T10:04:51.668119+01:00 deblndw011x.innomotics.net sshd-session 13838 - - error: PAM: Authentication error for illegal user AD7M26R4@ad007.siemens.net from demchhc0dbx.hca.siemens.de
<38>1 2025-12-24T10:04:51.668608+01:00 deblndw011x.innomotics.net sshd-session 13838 - - Failed keyboard-interactive/pam for invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 57556 ssh2
<38>1 2025-12-24T10:04:51.694973+01:00 deblndw011x.innomotics.net sshd-session 13838 - - Failed password for invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 57556 ssh2
<38>1 2025-12-24T10:04:51.723271+01:00 deblndw011x.innomotics.net sshd-session 13838 - - Connection closed by invalid user AD7M26R4@ad007.siemens.net 139.25.231.134 port 57556 [preauth]
<38>1 2025-12-24T10:04:52.088046+01:00 deblndw011x.innomotics.net sshd-session 13844 - - Invalid user Fortimanager_Access from 139.25.231.134 port 57578
<38>1 2025-12-24T10:04:52.120184+01:00 deblndw011x.innomotics.net sshd-session 13844 - - Postponed keyboard-interactive for invalid user Fortimanager_Access from 139.25.231.134 port 57578 ssh2 [preauth]
<35>1 2025-12-24T10:04:52.140961+01:00 deblndw011x.innomotics.net sshd-session 13844 - - error: PAM: Authentication error for illegal user Fortimanager_Access from demchhc0dbx.hca.siemens.de
<38>1 2025-12-24T10:04:52.141439+01:00 deblndw011x.innomotics.net sshd-session 13844 - - Failed keyboard-interactive/pam for invalid user Fortimanager_Access from 139.25.231.134 port 57578 ssh2
<38>1 2025-12-24T10:04:52.165672+01:00 deblndw011x.innomotics.net sshd-session 13844 - - Failed none for invalid user Fortimanager_Access from 139.25.231.134 port 57578 ssh2
<38>1 2025-12-24T10:04:52.197158+01:00 deblndw011x.innomotics.net sshd-session 13844 - - Connection closed by invalid user Fortimanager_Access 139.25.231.134 port 57578 [preauth]

@ziaee Any idea who I can request a review for this?

jrm requested changes to this revision.Sat, Dec 27, 5:00 AM

The underlying issue is real, but relying on a sysrc check seems fragile. The contents of /etc/rc.conf describe how syslogd should be started, but not necessarily how the currently running instance was started. For example, the user may have changed the configuration but not restarted the daemon. Also, the proposed flag-matching logic is brittle. For example, something like syslogd_flags="-N -ss -O rfc5424 is probably valid (untested) for syslogd, but wouldn't match your pattern.

Two alternatives come to mind:

  1. "Taste" the log file to determine which timestamp format is in use.
  2. Examine the arguments of the running syslogd, e.g. with `ps -axo command | grep '^/usr/sbin/syslogd '.
This revision now requires changes to proceed.Sat, Dec 27, 5:00 AM

Fair points!

In D54361#1242707, @jrm wrote:

The underlying issue is real, but relying on a sysrc check seems fragile. The contents of /etc/rc.conf describe how syslogd should be started, but not necessarily how the currently running instance was started. For example, the user may have changed the configuration but not restarted the daemon. Also, the proposed flag-matching logic is brittle. For example, something like syslogd_flags="-N -ss -O rfc5424 is probably valid (untested) for syslogd, but wouldn't match your pattern.

Correct, it wouldn't match. It need to test this. Is *-O*syslog*|*-O*rfc5424*) better in your opinion?

Two alternatives come to mind:

  1. "Taste" the log file to determine which timestamp format is in use.

This causes inner pain.

  1. Examine the arguments of the running syslogd, e.g. with `ps -axo command | grep '^/usr/sbin/syslogd '.

This is better, but not compelete since it would also show the processes running in jails which might be different. -J0 does the trick. Let me pay around with it. We can't take the PID file because it could have been altered as well and then we are back to the same situation. If we make this comprise we could use:

$ pargs 1544
1544:  syslogd
argv[0]: /usr/sbin/syslogd
argv[1]: -N
argv[2]: -ss
argv[3]: -O
argv[4]: rfc5424

WDYT? Ideally, I have the PID and the rest is not a problem anymore.

Is the rest of the code acceptable?

The extra spaces are consumed:

osipovmi@deblndw011x:/var/run
$ sysrc syslogd_flags
syslogd_flags: -N -ss -O     rfc5424
osipovmi@deblndw011x:/var/run
$ ps -J0 -axo command  | grep syslogd
/usr/sbin/syslogd -N -ss -O rfc5424
grep syslogd

Not a problem.

@jrm: Now it is calculated dynamically. Output from a jail:

root@deblndw011x2j:/etc/periodic
# security/800.loginfail

 login failures:
<38>1 2025-12-26T16:13:18.154398+01:00 deblndw011x2j.innomotics.net sshd-session 16123 - - Invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 3852
<38>1 2025-12-26T16:13:18.482344+01:00 deblndw011x2j.innomotics.net sshd-session 16123 - - Postponed keyboard-interactive for invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 3852 ssh2 [preauth]
<35>1 2025-12-26T16:13:18.499570+01:00 deblndw011x2j.innomotics.net sshd-session 16123 - - error: PAM: Authentication error for illegal user AD7M26R4@ad007.siemens.net from demchhc0dbx.hca.siemens.de
<38>1 2025-12-26T16:13:18.500037+01:00 deblndw011x2j.innomotics.net sshd-session 16123 - - Failed keyboard-interactive/pam for invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 3852 ssh2
<38>1 2025-12-26T16:13:18.524908+01:00 deblndw011x2j.innomotics.net sshd-session 16123 - - Connection closed by invalid user AD7M26R4@ad007.siemens.net 139.25.231.134 port 3852 [preauth]
<38>1 2025-12-26T16:13:18.823408+01:00 deblndw011x2j.innomotics.net sshd-session 16126 - - Invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 47982
<38>1 2025-12-26T16:13:19.138645+01:00 deblndw011x2j.innomotics.net sshd-session 16126 - - Postponed keyboard-interactive for invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 47982 ssh2 [preauth]
<35>1 2025-12-26T16:13:19.157005+01:00 deblndw011x2j.innomotics.net sshd-session 16126 - - error: PAM: Authentication error for illegal user uawet448@ad001.siemens.net from demchhc0dbx.hca.siemens.de
<38>1 2025-12-26T16:13:19.157734+01:00 deblndw011x2j.innomotics.net sshd-session 16126 - - Failed keyboard-interactive/pam for invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 47982 ssh2
<38>1 2025-12-26T16:13:19.182468+01:00 deblndw011x2j.innomotics.net sshd-session 16126 - - Connection closed by invalid user uawet448@ad001.siemens.net 139.25.231.134 port 47982 [preauth]
<38>1 2025-12-26T16:13:19.474529+01:00 deblndw011x2j.innomotics.net sshd-session 16130 - - Invalid user jboss from 139.25.231.134 port 47992
<38>1 2025-12-26T16:13:19.507033+01:00 deblndw011x2j.innomotics.net sshd-session 16130 - - Postponed keyboard-interactive for invalid user jboss from 139.25.231.134 port 47992 ssh2 [preauth]
<35>1 2025-12-26T16:13:19.525610+01:00 deblndw011x2j.innomotics.net sshd-session 16130 - - error: PAM: Authentication error for illegal user jboss from demchhc0dbx.hca.siemens.de
<38>1 2025-12-26T16:13:19.526070+01:00 deblndw011x2j.innomotics.net sshd-session 16130 - - Failed keyboard-interactive/pam for invalid user jboss from 139.25.231.134 port 47992 ssh2
<38>1 2025-12-26T16:13:19.550612+01:00 deblndw011x2j.innomotics.net sshd-session 16130 - - Connection closed by invalid user jboss 139.25.231.134 port 47992 [preauth]
<38>1 2025-12-26T16:13:19.843577+01:00 deblndw011x2j.innomotics.net sshd-session 16133 - - Invalid user jboss from 139.25.231.134 port 47998
<38>1 2025-12-26T16:13:19.876271+01:00 deblndw011x2j.innomotics.net sshd-session 16133 - - Postponed keyboard-interactive for invalid user jboss from 139.25.231.134 port 47998 ssh2 [preauth]
<35>1 2025-12-26T16:13:19.895086+01:00 deblndw011x2j.innomotics.net sshd-session 16133 - - error: PAM: Authentication error for illegal user jboss from demchhc0dbx.hca.siemens.de
<38>1 2025-12-26T16:13:19.895538+01:00 deblndw011x2j.innomotics.net sshd-session 16133 - - Failed keyboard-interactive/pam for invalid user jboss from 139.25.231.134 port 47998 ssh2
<38>1 2025-12-26T16:13:19.920249+01:00 deblndw011x2j.innomotics.net sshd-session 16133 - - Connection closed by invalid user jboss 139.25.231.134 port 47998 [preauth]

where deblndw011x is the jailhost.

usr.sbin/periodic/etc/daily/460.status-mail-rejects
39

I see a few problems with case "$(ps -p $(pgrep -j none syslogd) -o command= 2> /dev/null)" in.

  1. pgrep -j none syslogd will match multiple processes. On my laptop, the output is:
% ps -p $(pgrep -j none syslogd)
 PID TT  STAT    TIME COMMAND
3906  -  SCs  0:00.16 /usr/sbin/syslogd -N -ss -O rfc5424
3909  -  I    0:00.00 syslogd: syslogd.casper (syslogd)
3910  -  Is   0:00.00 syslogd: system.net (syslogd)

Also, there are problems with the whole command you're using to get the arguments.

% ps -p $(pgrep -j none syslogd) -o command=
ps: illegal argument: -o

usage: ps [--libxo] [-aCcdeHhjlmrSTuvwXxZ] [-O fmt | -o fmt]
          [-G gid[,gid...]] [-J jid[,jid...]] [-M core] [-N system]
          [-p pid[,pid...]] [-t tty[,tty...]] [-U user[,user...]]
          [-D up | down | both]
       ps [--libxo] -L
usr.sbin/periodic/etc/daily/460.status-mail-rejects
39

That's a good catch. The first one is likely solved with the current update. The second command has been changed to fit the usage, but will fail id pgrep does not find any process. In your case -o has been passed as the arg for -p.

Can you give it another try with the new change?

Looking at the diff, I don't see any obvious problems now. Ideally, you can test this for a few days to confirm everything is working as expected.

I can confirm your observations:

root@deblndw013x10v:~/freebsd-src (main %>)
# ps -o command= -p $(pgrep syslogd)
/usr/sbin/syslogd -N -ss -O rfc5424
syslogd: syslogd.casper (syslogd)
syslogd: system.net (syslogd)
root@deblndw013x10v:~/freebsd-src (main %>)
# uname -a
FreeBSD deblndw013x10v.innomotics.net 16.0-CURRENT FreeBSD 16.0-CURRENT #1 use-iso-8601-build-n282325-56b9c752e8d6: Fri Dec  5 18:14:04 CET 2025     root@deblndw013x10v.innomotics.net:/usr/obj/root/freebsd-src/amd64.amd64/sys/GENERIC amd64

Will install them and let them run for a few days...

Today's security message from a 16-CURRENT VM:

Checking setuid files and devices:

Checking negative group permissions:

Checking for uids of 0:
root 0
toor 0

Checking for passwordless accounts:

Checking login.conf permissions:

deblndw013x10v.innomotics.net login failures:
<38>1 2025-12-29T20:45:27.473720+01:00 deblndw013x10v.innomotics.net sshd-session 53312 - - Invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 5612
<38>1 2025-12-29T20:45:27.885032+01:00 deblndw013x10v.innomotics.net sshd-session 53312 - - Postponed keyboard-interactive for invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 5612 ssh2 [preauth]
<35>1 2025-12-29T20:45:27.905372+01:00 deblndw013x10v.innomotics.net sshd-session 53312 - - error: PAM: Authentication error for illegal user AD7M26R4@ad007.siemens.net from demchhc0dbx.hca.siemens.de
<38>1 2025-12-29T20:45:27.906357+01:00 deblndw013x10v.innomotics.net sshd-session 53312 - - Failed keyboard-interactive/pam for invalid user AD7M26R4@ad007.siemens.net from 139.25.231.134 port 5612 ssh2
<38>1 2025-12-29T20:45:27.931109+01:00 deblndw013x10v.innomotics.net sshd-session 53312 - - Connection closed by invalid user AD7M26R4@ad007.siemens.net 139.25.231.134 port 5612 [preauth]
<38>1 2025-12-29T20:45:28.289872+01:00 deblndw013x10v.innomotics.net sshd-session 53315 - - Invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 5646
<38>1 2025-12-29T20:45:28.696188+01:00 deblndw013x10v.innomotics.net sshd-session 53315 - - Postponed keyboard-interactive for invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 5646 ssh2 [preauth]
<35>1 2025-12-29T20:45:28.717501+01:00 deblndw013x10v.innomotics.net sshd-session 53315 - - error: PAM: Authentication error for illegal user uawet448@ad001.siemens.net from demchhc0dbx.hca.siemens.de
<38>1 2025-12-29T20:45:28.718518+01:00 deblndw013x10v.innomotics.net sshd-session 53315 - - Failed keyboard-interactive/pam for invalid user uawet448@ad001.siemens.net from 139.25.231.134 port 5646 ssh2
<38>1 2025-12-29T20:45:28.743293+01:00 deblndw013x10v.innomotics.net sshd-session 53315 - - Connection closed by invalid user uawet448@ad001.siemens.net 139.25.231.134 port 5646 [preauth]
<38>1 2025-12-29T20:45:29.134031+01:00 deblndw013x10v.innomotics.net sshd-session 53318 - - Invalid user admin from 139.25.231.134 port 49356
<38>1 2025-12-29T20:45:29.167425+01:00 deblndw013x10v.innomotics.net sshd-session 53318 - - Postponed keyboard-interactive for invalid user admin from 139.25.231.134 port 49356 ssh2 [preauth]
<35>1 2025-12-29T20:45:29.189781+01:00 deblndw013x10v.innomotics.net sshd-session 53318 - - error: PAM: Authentication error for illegal user admin from demchhc0dbx.hca.siemens.de
<38>1 2025-12-29T20:45:29.190635+01:00 deblndw013x10v.innomotics.net sshd-session 53318 - - Failed keyboard-interactive/pam for invalid user admin from 139.25.231.134 port 49356 ssh2
<38>1 2025-12-29T20:45:29.216022+01:00 deblndw013x10v.innomotics.net sshd-session 53318 - - Connection closed by invalid user admin 139.25.231.134 port 49356 [preauth]
<38>1 2025-12-29T20:45:29.531608+01:00 deblndw013x10v.innomotics.net sshd-session 53321 - - Invalid user admin from 139.25.231.134 port 49368
<38>1 2025-12-29T20:45:29.565024+01:00 deblndw013x10v.innomotics.net sshd-session 53321 - - Postponed keyboard-interactive for invalid user admin from 139.25.231.134 port 49368 ssh2 [preauth]
<35>1 2025-12-29T20:45:29.586453+01:00 deblndw013x10v.innomotics.net sshd-session 53321 - - error: PAM: Authentication error for illegal user admin from demchhc0dbx.hca.siemens.de
<38>1 2025-12-29T20:45:29.587251+01:00 deblndw013x10v.innomotics.net sshd-session 53321 - - Failed keyboard-interactive/pam for invalid user admin from 139.25.231.134 port 49368 ssh2
<38>1 2025-12-29T20:45:29.612158+01:00 deblndw013x10v.innomotics.net sshd-session 53321 - - Connection closed by invalid user admin 139.25.231.134 port 49368 [preauth]

deblndw013x10v.innomotics.net refused connections:

Checking for security vulnerabilities in base (userland & kernel):
Fetching vuln.xml.xz: .......... done
0 problem(s) in 0 package(s) found.
vulnxml file up-to-date
0 problem(s) in 0 package(s) found.

Checking for packages with security vulnerabilities:
Database fetched: 2025-12-29T18:00+01:00
libxslt-1.1.43_1
python310-3.10.18

Checking for packages with mismatched checksums:

-- End of security output --

This looks good to me...

@jrm, are we good now? I'd like to complete this.

Michael, take a look at https://reviews.freebsd.org/D54606, which might be a cleaner approach.

In D54361#1247638, @jrm wrote:

Michael, take a look at https://reviews.freebsd.org/D54606, which might be a cleaner approach.

Absolutely, looking into it.