Bug 1163742

Summary: "debug_timestamps = false" and "debug_microseconds = true" do not work after enabling journald with sssd.
Product: Red Hat Enterprise Linux 7 Reporter: Nirupama Karandikar <nkarandi>
Component: sssdAssignee: Michal Zidek <mzidek>
Status: CLOSED ERRATA QA Contact: Kaushik Banerjee <kbanerje>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.1CC: grajaiya, jgalipea, jhrozek, lslebodn, mkosek, mzidek, nsoman, pbrezina, preichl, sbose, sssd-maint
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: sssd-1.12.2-20.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-03-05 10:34:16 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 Nirupama Karandikar 2014-11-13 11:42:27 UTC
Description of problem:
"debug_timestamps = false" and "debug_microseconds = true" do not affect after enabling journald with sssd.

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

How reproducible:
Always

Steps to Reproduce:

1. Enable journald for sssd debug logging

2. Add "debug_timestamps = false" in sssd section and "debug_microseconds = true" in nss section of sssd.conf file.

3. From "journalctl -f" output

----------------------------------------
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: dbus conn: 0x7fc1b5a32260
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Dispatching.
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Service LDAP replied to ping
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: 0x7fc1b5a32a90
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: dbus conn: 0x7fc1b5a359e0
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Dispatching.
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Service pam replied to ping
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: 0x7fc1b5a353d0
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: dbus conn: 0x7fc1b5a33920
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Dispatching.
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Service nss replied to ping
----------------------------------------                                                                

From "journalctl -f" output

---------------------------------------------
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Added timed event "ltdb_timeout": 0x7f84e95b3d00
                                                                    
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Running timer event 0x7f84e95bf960 "ltdb_callback"
                                                                    
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Destroying timer event 0x7f84e95b3d00 "ltdb_timeout"
                                                                    
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Ending timer event 0x7f84e95bf960 "ltdb_callback"
---------------------------------------------                                                                    
Actual results:

From "journalctl -f" output

----------------------------------------
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: dbus conn: 0x7fc1b5a32260
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Dispatching.
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Service LDAP replied to ping
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: 0x7fc1b5a32a90
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: dbus conn: 0x7fc1b5a359e0
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Dispatching.
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Service pam replied to ping
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: 0x7fc1b5a353d0
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: dbus conn: 0x7fc1b5a33920
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Dispatching.
Nov 13 17:11:01 dhcp207-182.lab.eng.pnq.redhat.com sssd[12980]: Service nss replied to ping
----------------------------------------                                                                

From "journalctl -f" output

---------------------------------------------
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Added timed event "ltdb_timeout": 0x7f84e95b3d00
                                                                    
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Running timer event 0x7f84e95bf960 "ltdb_callback"
                                                                    
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Destroying timer event 0x7f84e95b3d00 "ltdb_timeout"
                                                                    
Nov 13 17:10:52 dhcp207-182.lab.eng.pnq.redhat.com sssd_nss[12982]: Ending timer event 0x7f84e95bf960 "ltdb_callback"
---------------------------------------------                                                                    

like both options do not affect

Expected results:

"debug_timestamps = false" and "debug_microseconds = true"

Additional info:

Disabling journald for sssd logging and everything works fine.

Comment 2 Sumit Bose 2014-11-13 15:05:03 UTC
I wonder if

journalctl -f -o short-precise

is what you are looking for?

Comment 3 Michal Zidek 2014-11-13 16:18:13 UTC
Hi,

this is a documentation issue. If journald is used, these options are ignored. I will send a patch to note this in the man pages.

Btw. to view microseconds with journalct use the --output=short-precise (see man journalctl for other output formats).

Comment 4 Jakub Hrozek 2014-11-18 08:59:29 UTC
Upstream ticket:
https://fedorahosted.org/sssd/ticket/2498

Comment 5 Jakub Hrozek 2014-11-20 10:34:54 UTC
* master: cbbe63ded9d628ffb2494132ca1e5ebe90e2d5f8

Comment 7 Nirupama Karandikar 2015-01-13 12:46:24 UTC
Tested with sssd-1.12.2-39.el7.x86_64

1. Install sssd-1.12.2-39.el7.x86_64.

2. From "man sssd.conf"

debug_timestamps (bool)
           Add a timestamp to the debug messages. If journald is enabled for SSSD debug logging this option is ignored.

debug_microseconds (bool)
           Add microseconds to the timestamp in debug messages. If journald is enabled for SSSD debug logging this option is ignored.

Comment 9 errata-xmlrpc 2015-03-05 10:34:16 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://rhn.redhat.com/errata/RHBA-2015-0441.html