[Bug 1908065] Re: Invalid SYSLOG_PID for (systemd) journal messages

[Valters Jansons]

Sorry Dan, I did not initially grasp the full implication of your
message if it was intended that way. Thank you for the upstream commit
linked.

Will poke around a bit more and provide a proposed debdiff to be
sponspored then, but to summarize from SSSD side: indeed not
reproducible with a minimal C program (and is indeed Status: Invalid for
systemd) as the sd_journal_send() branch never actually runs from SSSD
side. The rules override_dh_auto_configure does not set --with-
syslog=journald in the Focal version, and instead leaves the default
--with-syslog=syslog path, indicated by Journald showing
_TRANSPORT=syslog as well. That must be where the SYSLOG_PID parsing
comes in to play, and that is the reason why the syslog messages are
indeed malformed the way they are.

The newer packages (for 20.10 and 21.04) set the Journald logging
configuration flag, and have the referenced program name clean-up
commit.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1908065

Title:
  Invalid SYSLOG_PID for (systemd) journal messages

Status in sssd package in Ubuntu:
  Triaged
Status in systemd package in Ubuntu:
  Invalid

Bug description:
  [Impact]

   * On Ubuntu (Focal) 20.04, SSSD 2.2.3-3, logs in Journald have
  invalid (non-numeric) SYSLOG_PID. Any tooling collecting SYSLOG_PID
  further, or attempting to work with syslog directly, fail to parse the
  PID as number.

   * Systemd does not validate, and simply expects SYSLOG_PID as numeric integers formatted as decimal strings:
     https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html#SYSLOG_FACILITY=

  [Test Case]

   * Deploy fresh 20.04 image, and update:
     apt update && apt dist-upgrade

   * apt -qqy install sssd

   * cat << EOF > /etc/sssd/sssd.conf
  [sssd]
    config_file_version = 2
    domains = EXAMPLE.COM
    services =

  [nss]

  [pam]

  [sudo]

  [domain/EXAMPLE.COM]
    id_provider = files
    access_provider = permit
  EOF

   * chmod 600 /etc/sssd/sssd.conf

   * systemctl restart sssd.service

   * journalctl -o verbose -u sssd-sudo.service | grep SYSLOG_PID=
     SYSLOG_PID=sudo

   * journalctl -u sssd.service # Produces malformed example lines:
     Dec 07 14:10:00 servername sssd[be[1234]: Starting up

   * grep sssd /var/log/syslog # Displays non-numeric PIDs:
     Dec  7 08:00:00 servername sssd[be[EXAMPLE.COM]]: Starting up
     Dec  7 08:00:00 servername sssd[nss]: Starting up
     Dec  7 08:00:00 servername sssd[sudo]: Starting up
     Dec  7 08:00:00 servername sssd[pam]: Starting up

  [Where problems could occur]

   * Someone might depend on the malformed output already, and have
  tooling in place to transform it manually.

  [Other Info]

   * Is not reproducible on Ubuntu (Groovy) 20.10 containing SSSD
  2.3.1-3. Considering Debian testing is currently at SSSD 2.4.0-1, it
  does not appear applicable to fix in upstream.

   * The package itself does not appear to provide any SYSLOG_PID. The
  SYSLOG_IDENTIFIER appears to instead 'leak' over into PID, hinting at
  trouble on systemd side. SSSD source at:
  https://github.com/SSSD/sssd/blob/sssd-2_2_3/src/util/sss_log.c#L110

   * Applying a change to SYSLOG_IDENTIFIER (prefixing with "sssd[" and suffixing with "]") results in "SYSLOG_IDENTIFIER=sssd_be" being logged, and no SYSLOG_PID being reported.
     Cherry-picked upstream commit for testing: https://github.com/SSSD/sssd/commit/18233532b72e62452eac6886652fa633ba055d8c

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/sssd/+bug/1908065/+subscriptions