[SSSD] RFC: Improving the debug messages

Pavel Březina pbrezina at redhat.com
Thu Oct 1 07:58:07 UTC 2015


On 09/29/2015 07:53 PM, Jakub Hrozek wrote:
> 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.

I don't oppose, but I have to ask. Is there really any developer who 
reads debug levels when debugging? I personally only read messages and 
I'd prefer to see smaller lines.

>
> 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.
> _______________________________________________
> sssd-devel mailing list
> sssd-devel at lists.fedorahosted.org
> https://lists.fedorahosted.org/mailman/listinfo/sssd-devel
>



More information about the sssd-devel mailing list