[SSSD] RFC: Improving the debug messages

Jakub Hrozek jhrozek at redhat.com
Tue Sep 29 17:53:41 UTC 2015


On Tue, Sep 29, 2015 at 06:15:35PM +0200, Sumit Bose wrote:
> On Tue, Sep 29, 2015 at 05:57:32PM +0200, Jakub Hrozek wrote:
> > On Mon, Sep 28, 2015 at 10:18:07AM +0200, Sumit Bose wrote:
> > > On Mon, Jun 29, 2015 at 11:07:30PM -0400, Dan Lavu wrote:
> > > > I've been watching various logs for the past few minutes, FWIW, I think a more casual message will help people better understand what SSSD is doing. Look at debug level 4, the first instance of a user name look up (getent passwd dlavu) a common command we tell folks to test to see if SSSD is working 
> > > > 
> > > > (Mon Jun 29 22:10:59 2015) [sssd[be[lab.runlevelone.lan]]] [be_get_account_info] (0x0200): Got request for [0x1001][1][name=dlavu] 
> > > > 
> > > > Just imagine if you knew nothing about SSSD and how it worked, what can you gather from this line of text? Timestamp, process, domain, get_account_info, got_request and userid and the rest is sort of gibberish and what is the difference between be_get_account_info and got_request_for? I think it's confusing, now looking at some other logs messages. 
> > > 
> > > What is missing in the list of components above is '(0x0200)' which is
> > > the debug_level.  We recently had a number of questions about messages
> > > from a high debug level which in general have an information character,
> > > but since it not easy to identify the level of the message it was
> > > considered as an error message. Maybe it would be good to have a some
> > > translations here as well to make it easier to separate errors from
> > > infos.
> > 
> > Do you mean printing the level as string, so that instead of:
> >     [sssd[be[lab.runlevelone.lan]]] [be_get_account_info] (0x0200): Got request for [0x1001][1][name=dlavu] 
> > we would have:
> >     [sssd[be[lab.runlevelone.lan]]] [be_get_account_info] (SSSDBG_FUNC_DATA): Got request for [0x1001][1][name=dlavu] 
> > 
> > ?
> > 
> > If yes, then I agree. But at the same time, I think it's more irritating
> 
> yes, that's what I meant, but maybe we should not use the internal
> macros here, but something more explicit like ERR_CRIT, ERR_FUNC,
> INF_CONFIG, INF_DATA, TRACE_... to make it more obvious what the message
> might be about.

Yes, sure. Care to file a ticket? :-)

> 
> > that so many debug levels (mainly those that were mass-converted) are
> > misplaced.
> 
> of course, but maybe having the level spelled out will help to identify
> the ones that are misplaced more easy?

Yes, it would be easier to read a word than a hexa number. We could
even colorize the output when running interactively :-)

What we can also do easily and with relatively low effort is to
select a couple of the most common usage patterns like:
    * login with the correct password, online and offline
    * login with wrong password
    * run sudo
    * change password
    * ....

And make sure they don't print any messages with debug_level <= 3.


More information about the sssd-devel mailing list