Bug 1460724

Summary: SYSLOG_IDENTIFIER is different
Product: Red Hat Enterprise Linux 7 Reporter: Madhuri <mupadhye>
Component: sssdAssignee: Lukas Slebodnik <lslebodn>
Status: CLOSED ERRATA QA Contact: Madhuri <mupadhye>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.4CC: fidencio, grajaiya, jhrozek, lslebodn, mkosek, mupadhye, mzidek, orion, pbrezina, sgoveas, tscherf
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: sssd-1.16.0-4.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-04-10 17:11:33 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Madhuri 2017-06-12 14:00:21 UTC
Description of problem:
SYSLOG_IDENTIFIER is different

Version-Release number of selected component (if applicable):
sssd-1.15.2-43.el7.x86_64

How reproducible:
Always

Steps to Reproduce:
1. Edit the /etc/systemd/system/sssd.service.d/journal.conf.
2. Set "debug_level = 9" in all sssd section.
3. #systemctl daemon-reload.
4. Restart the sssd.
5. check SYSLOG_IDENTIFIER. 

Actual results:
SYSLOG_IDENTIFIER is sssd for all responder .

# journalctl -r --output=json | head -n1
{ "__CURSOR" : "s=ba4284a74f264f70a04df4abbad7dd66;i=4d3c;b=44fa6a20417849b38e434e437ba7081a;m=537d78c390;t=551c28926743e;x=d175c6fdfdb4f440", "__REALTIME_TIMESTAMP" : "1497270850057278", "__MONOTONIC_TIMESTAMP" : "358587351952", "_BOOT_ID" : "44fa6a20417849b38e434e437ba7081a", "_TRANSPORT" : "stdout", "PRIORITY" : "6", "SYSLOG_FACILITY" : "3", "SYSLOG_IDENTIFIER" : "sssd", "_UID" : "0", "_GID" : "0", "_COMM" : "sssd", "_EXE" : "/usr/sbin/sssd", "_CMDLINE" : "/usr/sbin/sssd -i", "_CAP_EFFECTIVE" : "1fffffffff", "_SYSTEMD_CGROUP" : "/system.slice/sssd.service", "_SYSTEMD_UNIT" : "sssd.service", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:init_t:s0", "_MACHINE_ID" : "9b03e1ea405a5c2855cd1e9599d5c2a6", "_HOSTNAME" : "client_multiple.example.com", "_PID" : "25171", "MESSAGE" : "(Mon Jun 12 08:34:09 2017) [sssd[nss]] [client_close_fn] (0x2000): Terminated client [0x55d6410b6c70][20]" }

Expected results:
SYSLOG_IDENTIFIER for nss responder should sssd_nss or sssd_pam for pam responder.

Additional info:

Comment 3 Lukas Slebodnik 2017-06-13 08:35:32 UTC
We still kind of log to journald but log messages are not structured as before.
Because we log to stdout/err and systemd forward logs to journald. This is a reason why SYSLOG_IDENTIFIER has a wrong value and MESSAGE contain timestamp generated by sssd.

We are not able to log directly into journald with interactive mode. we might need to introduce new command line option. Or use more complicated template for loggind into journald.

[Service]
# Uncomment following lines to enable debug logging
# to go to journald instead of /var/log/sssd. You will need to
# run 'systemctl daemon-reload' and then restart the SSSD service
# for this to take effect
#ExecStart=
#ExecStart=/usr/sbin/sssd -D
#NotifyAccess=all
#PIDFile=/var/run/sssd.pid

Comment 6 Jakub Hrozek 2017-06-15 14:22:56 UTC
Upstream ticket:
https://pagure.io/SSSD/sssd/issue/3433

Comment 7 Lukas Slebodnik 2017-11-03 08:45:56 UTC
master:
* 18a47bcc463c866de6b6b0327e6d85ceb1e0f7d6
* 115145f0fb7507c1b9c5489bc77398d422a66875
* a7277fecf7a65ab6c83b36f009c558cdfbf997d2
* cb75b275d15beedd1fdecc1f8ced657fba282218
* 09e3f0af96cecb94be69084c025f0355b3111993

Comment 9 Lukas Slebodnik 2017-11-06 18:37:15 UTC
*** Bug 1510088 has been marked as a duplicate of this bug. ***

Comment 10 Lukas Slebodnik 2017-11-07 10:04:56 UTC
Patches caused regression that child logs were not sent to files.

Comment 11 Lukas Slebodnik 2017-11-10 13:08:18 UTC
master:
* a24954cc19285b197fb287bfa7aa01949c92b17d
* f4b808c83ecbaf36c7069440535d62990e32d55d
* b495522f3eadde9ad4bb8d125fd70b0d5f07596a

Comment 12 Madhuri 2018-01-17 10:13:25 UTC
Verified with
# rpm -qa sssd
sssd-1.16.0-14.el7.x86_64

Verification Steps:
1. Edit /etc/sysconfig/sssd.
   echo "DEBUG_LOGGER=--logger=journald" >> /etc/sysconfig/sssd
2. Set "debug_level = 9" in all sssd section.
3. Restart the sssd.
4. check SYSLOG_IDENTIFIER. 

# pgrep -af sssd
29713 /usr/sbin/sssd -i --logger=journald
29714 /usr/libexec/sssd/sssd_be --domain LDAP --uid 0 --gid 0 --logger=journald
29715 /usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --logger=journald
29716 /usr/libexec/sssd/sssd_pam --uid 0 --gid 0 --logger=journald
29717 /usr/libexec/sssd/sssd_sudo --uid 0 --gid 0 --logger=journald
29718 /usr/libexec/sssd/sssd_autofs --uid 0 --gid 0 --logger=journald
29719 /usr/libexec/sssd/sssd_ssh --uid 0 --gid 0 --logger=journald
29720 /usr/libexec/sssd/sssd_pac --uid 0 --gid 0 --logger=journald
29721 /usr/libexec/sssd/sssd_ifp --uid 0 --gid 0 --logger=journald

#  journalctl -r --output=json SYSLOG_IDENTIFIER=sssd_pam | head -n1
{ "__CURSOR" : "s=f492a6e338254acca2788f212361e91d;i=b33a;b=e04f5c08d2fd41b79861ad7e1caa10b0;m=14ce0ff3c6;t=5628f21f5fcf4;x=62c076d408270941", "__REALTIME_TIMESTAMP" : "1515741773167860", "__MONOTONIC_TIMESTAMP" : "89356497862", "_BOOT_ID" : "e04f5c08d2fd41b79861ad7e1caa10b0", "PRIORITY" : "7", "SSSD_DEBUG_LEVEL" : "4000", "_TRANSPORT" : "journal", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "1fffffffff", "_SYSTEMD_CGROUP" : "/system.slice/sssd.service", "_SYSTEMD_UNIT" : "sssd.service", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:sssd_t:s0", "_MACHINE_ID" : "4940d7077146d2ac2807da29948f64c5", "_HOSTNAME" : "ipaqavmc.idmqe.lab.eng.bos.redhat.com", "CODE_FILE" : "src/sbus/sssd_dbus_connection.c", "SSSD_DOMAIN" : "", "_COMM" : "sssd_pam", "_EXE" : "/usr/libexec/sssd/sssd_pam", "_CMDLINE" : "/usr/libexec/sssd/sssd_pam --uid 0 --gid 0 --logger=journald", "CODE_LINE" : "46", "CODE_FUNC" : "sbus_dispatch", "SSSD_PRG_NAME" : "sssd[pam]", "SYSLOG_IDENTIFIER" : "sssd_pam", "_PID" : "31149", "MESSAGE" : "dbus conn: 0x5602db798030\n", "_SOURCE_REALTIME_TIMESTAMP" : "1515741772866334" }

#  journalctl -r --output=json SYSLOG_IDENTIFIER=sssd_nss | head -n1
{ "__CURSOR" : "s=f492a6e338254acca2788f212361e91d;i=16bf4;b=e04f5c08d2fd41b79861ad7e1caa10b0;m=51affc1e4f;t=562cc03e2277d;x=2de6bc5ffcb6d55f", "__REALTIME_TIMESTAMP" : "1516003261556605", "__MONOTONIC_TIMESTAMP" : "350844886607", "_BOOT_ID" : "e04f5c08d2fd41b79861ad7e1caa10b0", "PRIORITY" : "7", "_TRANSPORT" : "journal", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "1fffffffff", "_SYSTEMD_CGROUP" : "/system.slice/sssd.service", "_SYSTEMD_UNIT" : "sssd.service", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:sssd_t:s0", "_MACHINE_ID" : "4940d7077146d2ac2807da29948f64c5", "_HOSTNAME" : "ipaqavmc.idmqe.lab.eng.bos.redhat.com", "SSSD_DEBUG_LEVEL" : "2000", "CODE_FILE" : "src/responder/common/responder_common.c", "SSSD_DOMAIN" : "", "SSSD_PRG_NAME" : "sssd[nss]", "SYSLOG_IDENTIFIER" : "sssd_nss", "_PID" : "31148", "_COMM" : "sssd_nss", "_EXE" : "/usr/libexec/sssd/sssd_nss", "_CMDLINE" : "/usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --logger=journald", "CODE_LINE" : "94", "CODE_FUNC" : "client_close_fn", "MESSAGE" : "Terminated client [0x564a66b95710][20]\n", "_SOURCE_REALTIME_TIMESTAMP" : "1516003261555057" }

#  journalctl -r --output=json SYSLOG_IDENTIFIER=sssd_sudo | head -n1
{ "__CURSOR" : "s=f492a6e338254acca2788f212361e91d;i=b328;b=e04f5c08d2fd41b79861ad7e1caa10b0;m=14ce0fcf66;t=5628f21f5d895;x=18d5b4490d9063be", "__REALTIME_TIMESTAMP" : "1515741773158549", "__MONOTONIC_TIMESTAMP" : "89356488550", "_BOOT_ID" : "e04f5c08d2fd41b79861ad7e1caa10b0", "PRIORITY" : "7", "SSSD_DEBUG_LEVEL" : "4000", "_TRANSPORT" : "journal", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "1fffffffff", "_SYSTEMD_CGROUP" : "/system.slice/sssd.service", "_SYSTEMD_UNIT" : "sssd.service", "_SYSTEMD_SLICE" : "system.slice", "_SELINUX_CONTEXT" : "system_u:system_r:sssd_t:s0", "_MACHINE_ID" : "4940d7077146d2ac2807da29948f64c5", "_HOSTNAME" : "ipaqavmc.idmqe.lab.eng.bos.redhat.com", "CODE_FILE" : "src/sbus/sssd_dbus_connection.c", "SSSD_DOMAIN" : "", "_COMM" : "sssd_sudo", "_EXE" : "/usr/libexec/sssd/sssd_sudo", "_CMDLINE" : "/usr/libexec/sssd/sssd_sudo --uid 0 --gid 0 --logger=journald", "CODE_LINE" : "46", "CODE_FUNC" : "sbus_dispatch", "SSSD_PRG_NAME" : "sssd[sudo]", "SYSLOG_IDENTIFIER" : "sssd_sudo", "_PID" : "31150", "MESSAGE" : "dbus conn: 0x5570a5a7dda0\n", "_SOURCE_REALTIME_TIMESTAMP" : "1515741772852378" }

Comment 15 errata-xmlrpc 2018-04-10 17:11:33 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2018:0929