[SSSD] RFC: Improving the debug messages

Pavel Reichl preichl at redhat.com
Thu Oct 1 08:14:16 UTC 2015



On 10/01/2015 09:58 AM, Pavel Březina wrote:
> 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.

I think that this is not aimed for developers but for admins/users who when confronted with verbose debug file might be unnecessary scared from some debug messages. The idea is that if they see that the scary sounding message is just TRACE_ALL 
instead of 0x400 they might stop panicking.

>
>>
>> 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
>>
>
> _______________________________________________
> 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