On Tue, Nov 24, 2015 at 10:01:00AM +0100, Pavel Reichl wrote:
On 11/24/2015 09:50 AM, Jakub Hrozek wrote:
>On Mon, Nov 23, 2015 at 03:00:05PM +0100, Pavel Reichl wrote:
>>
>>
>>On 11/23/2015 02:53 PM, Lukas Slebodnik wrote:
>>>On (23/11/15 14:37), Pavel Reichl wrote:
>>>>
>>>>
>>>>On 11/23/2015 10:26 AM, Lukas Slebodnik wrote:
>>>>[snip]
>>>>>>
>>>>>>(And this is different than the 80-chars limit which still makes
sense
>>>>>>for developers who often like to vertically split their editors)
>>>>>>
>>>>>It's not about 80 character limit. We already does not meet this
criteria.
>>>>>Small example:
>>>>>(Mon Nov 23 10:12:24 2015) [sssd[be[ipa.corp.example.com]]]
[server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb
>>>>>
>>>>>Even the 190 columns is not enough for sme messages.
>>>>>(Mon Nov 23 10:12:24 2015) [sssd[be[ipa.corp.example.com]]]
[sbus_message_handler] (0x2000): Received SBUS method
org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider
>>>>>
>>>>>
>>>>>But with string representations it will be extra 20 columns.
>>>>
>>>>Yes, let's drop the number completely.
>>>>>
>>>>>>>
>>>>>>>>>>c) the size of logs will be increased.
>>>>>>>>>>"
>>>>>>>>>>
>>>>>>>>>>So... if INFO, ERROR, FATAL and so on are wrong,
well. Is there any idea how
>>>>>>>>>>to improve readability of logs?
>>>>>>>>>>
>>>>>>>>>Not the simple one.
>>>>>>>>>
>>>>>>>>>Firstly we need to fix point a) ; otherwise we will
just confuse users with
>>>>>>>>>any string representation of debug level.
>>>>>>>>
>>>>>>>>I think it would be enough to make sure that during the
most common
>>>>>>>>operations, there are no logs with failure levels. The
difference
>>>>>>>>between FUNC_DATA and TRACE_FUNC is small even to us,
much less to an
>>>>>>>>admin.
>>>>>>>So it might make sense to set clear difference between
FUNC_DATA and TRACE_FUNC
>>>>>>>(or other debug_levels) and check it as part of review.
>>>>>>>
>>>>>>>Otherwise it does not make a sense to use such variety of
debug levels.
>>>>>>>Because if difference is small to us (developers) then we can
merge them
>>>>>>>and simplify things.
>>>>>>
>>>>>>Maybe, but neither of this helps admins distinguish what messages
to
>>>>>>look for in the logs.
>>>>>
>>>>>String representation of debug_level will not help either.
>>>>
>>>>I don't agree. For random user the difference between 0x0010 and
0x4000 is
>>>>virtually non existing.
>>>But they can use old numbers. Which are mentioned in sssd.conf (1..9).
>>>The higher number means more verbose output. It still
>>>does not solve the problems with maping new debug levels to the semantic
>>>of that debug level. It can only be used just for increasing/decreasing
>>>a verbosity of log files.
>>>
>>>>But on contrary every code contributor is aware of
>>>>significant difference between fatal failure or trace all or previously
>>>>between 1 and 10. I support conversion of hexa numbers to strings as a
mean
>>>>for easier debugging by users.
>>>>
>>>One more time, The string representation will not help becuase @see point a)
>>>It will just confuse users. So it's better to not confuse users and
rather
>>>print hexadecimal number which does not say anything. (but can be
efficiently
>>>used for filtering)
>>
>>It seems that you are only one to think so.
>
>Well, I agree with one Lukas' point that we should convert at least the
>errors to something less verbose. Otherwise, check what messages we would
>mark as error during a single failed and successfull auth:
>
># sssd -i -d 3
>(Tue Nov 24 08:45:28 2015) [sssd[ifp]] [sbus_signal_handler_got_caller_id] (0x0080):
Received signal org.freedesktop.DBus.NameAcquired that we are not listening to.
>(Tue Nov 24 08:45:28 2015) [sssd[ifp]] [sbus_signal_handler_got_caller_id] (0x0080):
Received signal org.freedesktop.DBus.NameAcquired that we are not listening to.
>(Tue Nov 24 08:45:29 2015) [sssd[be[ipa.test]]] [be_run_online_cb] (0x0080): Going
online. Running callbacks.
>(Tue Nov 24 08:45:38 2015) [[sssd[krb5_child[6555]]]] [sss_krb5_prompter] (0x0020):
Cannot handle password prompts.
>(Tue Nov 24 08:45:38 2015) [sssd[be[ipa.test]]] [krb5_auth_store_creds] (0x0010):
unsupported PAM command [249].
>(Tue Nov 24 08:45:38 2015) [sssd[be[ipa.test]]] [krb5_auth_store_creds] (0x0010):
password not available, offline auth may not work.
>(Tue Nov 24 08:45:39 2015) [[sssd[krb5_child[6556]]]] [get_and_save_tgt] (0x0020):
1229: [-1765328360][Preauthentication failed]
>(Tue Nov 24 08:45:39 2015) [[sssd[krb5_child[6556]]]] [map_krb5_error] (0x0020):
1298: [-1765328360][Preauthentication failed]
>(Tue Nov 24 08:45:46 2015) [[sssd[krb5_child[6561]]]] [sss_krb5_prompter] (0x0020):
Cannot handle password prompts.
>(Tue Nov 24 08:45:46 2015) [sssd[be[ipa.test]]] [krb5_auth_store_creds] (0x0010):
unsupported PAM command [249].
>(Tue Nov 24 08:45:46 2015) [sssd[be[ipa.test]]] [krb5_auth_store_creds] (0x0010):
password not available, offline auth may not work.
>(Tue Nov 24 08:45:48 2015) [sssd[be[ipa.test]]] [ipa_hbac_evaluate_rules] (0x0080):
Access granted by HBAC rule [allow_all]
>(Tue Nov 24 08:45:48 2015) [[sssd[selinux_child[6563]]]] [get_seuser] (0x0040):
SELinux user for admin: unconfined_u
>(Tue Nov 24 08:45:48 2015) [[sssd[selinux_child[6563]]]] [get_seuser] (0x0040):
SELinux range for admin: s0-s0:c0.c1023
>(Tue Nov 24 08:45:48 2015) [sssd[nss]] [nss_cmd_getgrgid_search] (0x0080): No
matching domain found for [240000000]
I'm not sure I understand you properly here, but if you mean improving the
messages for errors I support that. I even more support checking and
cleaning the log messages for common use cases like logging in and queering
users as you already proposed. It just seems to me to be unrelated to this
ticket or rather much more complex task then this ticket should solve.
It's related because flagging the messages with some "ERROR" flag would
be even more misleading then if the messages are printed with the hexa
debug level.
So we should fix the error levels for the common operations first.