[Gluster-devel] Logging framework in Gluter 4.0

Tue Nov 10 06:36:04 UTC 2015

On Tue, Nov 10, 2015 at 12:05 PM, Kaushal M <kshlmster at gmail.com> wrote:
> On Fri, Nov 6, 2015 at 10:45 PM, Atin Mukherjee
> <atin.mukherjee83 at gmail.com> wrote:
>> -Atin
>> Sent from one plus one
>>
>>
>> On Nov 6, 2015 7:50 PM, "Shyam" <srangana at redhat.com> wrote:
>>>
>>> On 11/06/2015 06:58 AM, Atin Mukherjee wrote:
>>>>
>>>>
>>>>
>>>> On 11/06/2015 01:30 PM, Aravinda wrote:
>>>>>
>>>>>
>>>>> regards
>>>>> Aravinda
>>>>> http://aravindavk.in
>>>>>
>>>>> On 11/06/2015 12:28 PM, Avra Sengupta wrote:
>>>>>>
>>>>>> Hi,
>>>>>>
>>>>>> As almost all the components targeted for Gluster 4.0 have moved from
>>>>>> design phase to implementation phase on some level or another, I feel
>>>>>> it's time to get some consensus on the logging framework we are going
>>>>>> to use. Are we going to stick with the message ID formatted logging
>>>>>> framework in use today, or shall we move on to a better solution.
>>>
>>>
>>> I would prefer to think that we extend the log messages with what we want.
>>> Message IDs are there for a purpose as outlined in earlier mails on the same
>>> topic, so we [w|s]hould stick with message IDs and add more is how I think
>>> of the problem.
>>>
>>> If we take inspiration from other frameworks, I would say we improve what
>>> we log.
>>>
>>> Where we log is made pluggable in the current framework, although as we
>>> add more logging frameworks (like rsyslog or lumberjack etc.) the
>>> abstraction provided for plugging in these could improve. This is a
>>> contained change in the logging.c file though.
>>>
>>>
>>>>>>
>>>>>> Some good to have features I would like to have in the logging
>>>>>> framework are:
>>>>>> 1. Specific distinction between logs of various transactions (or
>>>>>> operations), that would make it a lot easier to make sense than
>>>>>> looking at some serialized log dump
>>>>>
>>>>> Externally grouping Message IDs may help in this situation.
>>>>
>>>> Transaction Id is definitely a *must have* requirement when 4.0's theme
>>>> is scalability where we are talking about number of servers been
>>>> thousands in the configuration with out which analysis of an issue will
>>>> be a nightmare. GlusterD 2.0 is definitely going to have logs with txn
>>>> ids.
>>>
>>>
>>> +1
>>>
>>> I thought this was discussed in another thread on the lists, not able to
>>> find it, a link would help.
>>>
>>> The question is, should this be automated by the logging framework, or
>>> something each xlator should do?
>>>
>>> I prefer automating this, but how? (frame pointers? at least on the IO
>>> xlator stack) What is glusterd doing for the same?
>> As of now we have started using logrus pkg in golang which logs every
>> message with its txn id. How it does is what I need to find out looking at
>> the pkg code (if you are looking to borrow the similar idea)
>>
>
> The logrus[1] package provides structured logging and ability to build
> incremental log contexts. This makes it possible to do things like
> message-ids. But IMO the advantage of using structured logging is that
> it would kind of remove the need for message-ids.
>
> In structured logging, it encouraged to keep the log string itself
> constant and keep the variable portions as metadata attached to the
> log, generally as key-value pairs. This allows us to implement things
> like message-ids, but it is not really required. As the log string is
> kept constant, it becomes easier to search for individual logs and
> document them. For example (not really the best example), currently we
> log socket failures in the following format
>
> "readv on some.socket failed (No data available)"
>
> This is hard to search for or parse, as the log string itself changes
> when the socket or error changes. If using structured logging, this
> log would be in the format
>
> "readv on socket failed socket=some.socket errno=ENODATA"
>
> This is much more easier to search and parse.
>
> Using log-contexts allows attaching a certain metadata to all logs in
> a context, for example, attaching transaction-ids to all logs of a
> transaction. If we were to use log-contexts above example we could
> attach the transaction-id to the log,
>
> "readv on socket failed socket=some.socket errno=ENODATA
> txn-id=<uuid-string-here>"
>
> allowing us to easily track during which transaction did the read fail.
>

(Missed the link)
[1]: https://github.com/sirupsen/logrus

>>>
>>>
>>>>>
>>>>>> 2. We often encounter issues, and then find ourselves wishing the
>>>>>> process was running in debug mode so that we could have gotten some
>>>>>> debug logs. If there is any solution that enables me tracability of
>>>>>> the process's flow, without compromising the space constraints of the
>>>>>> logs that would be great to have.
>>>>>
>>>>> I think after each debugging session, we should revise the log messages
>>>>> to get following answers.
>>>>> 1. Is something missing in log, which could have reduced the time spent
>>>>> to root cause.
>>>>> 2. Logging is available but imcomplete details. (For example, on volume
>>>>> set, debug message will have key and value but no Volume name)
>>>>> 3. Is something redundant or not required. (For example, Geo-replication
>>>>> worker logs sync engine as rsync or tar mode. If we have multiple
>>>>> workers then all workers prints this log message. Instead if we move
>>>>> this log to monitor process instead of worker process we could save some
>>>>> space in log files)
>>>>>
>>>>> With this practice, we can improve our logs over time.
>>>>
>>>> I do agree here with Aravinda, we can do a far better job even at INFO
>>>> log level than what we've been doing now.
>>>>>>
>>>>>>
>>>>>> This is kind of an open floor question I am putting across to the
>>>>>> community, with no specific solution in mind at this point in time,
>>>>>> but a concern that we should rather decide on something sooner in the
>>>>>> development cycle than later.
>>>>>>
>>>>>> Regards,
>>>>>> Avra
>>>>>> _______________________________________________
>>>>>> Gluster-devel mailing list
>>>>>> Gluster-devel at gluster.org
>>>>>> http://www.gluster.org/mailman/listinfo/gluster-devel
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> Gluster-devel mailing list
>>>>> Gluster-devel at gluster.org
>>>>> http://www.gluster.org/mailman/listinfo/gluster-devel
>>>>
>>>> _______________________________________________
>>>> Gluster-devel mailing list
>>>> Gluster-devel at gluster.org
>>>> http://www.gluster.org/mailman/listinfo/gluster-devel
>>>>
>>> _______________________________________________
>>> Gluster-devel mailing list
>>> Gluster-devel at gluster.org
>>> http://www.gluster.org/mailman/listinfo/gluster-devel
>>
>> -Atin
>> Sent from one plus one
>>
>>
>> _______________________________________________
>> Gluster-devel mailing list
>> Gluster-devel at gluster.org
>> http://www.gluster.org/mailman/listinfo/gluster-devel