Gluster users - Nov 2019 - [Gluster-Maintainers] [Gluster-devel] Modifying gluster's logging mechanism

Thank you for your input Atin and Xie Changlong.

Regarding log ordering - my initial thought was to do it offline using a
dedicated too. Should be straight forward, as the logs have time stamp
composed of seconds and microseconds, so ordering them using this value is
definitely possible.
This is actually one of the main reasons I wanted to bring this up for
discussion - will it be fine with the community to run a dedicated tool to
reorder the logs offline?
Reordering the logs offline will allow us to gain the most performance
improvement, as keeping the logs order online will have some cost (probably
through stronger synchronization).
Moreover, we can take log viewing one step further and maybe create some
GUI system (JAVA based?) to view and handle logs (e.g. one window to show
the combined order logs, other windows to show logs per thread etc').

Regarding the test method - my initial testing was done by removing all
logging from regression. Modifying the method "skip_logging" to return
'true' in all cases seems to remove most of the logs (though not all,
"to
be on the safe side", really removing all logging related methods is
probably even better).
As regression tests use mostly single-node tests, some additional testing
was needed. I've written a couple of very basic scripts to create large
number of files / big files, read / write to / from them, move them around
and perform some other basic functionality.
I'd actually be glad to test this in some 'real world' use cases -
if you
have specific use cases that you use frequently, we can model them and
benchmark against - this will likely offer an even more accurate benchmark.

On Fri, Nov 22, 2019 at 7:27 AM Xie Changlong <zgrep at 139.com> wrote:
>
> ? 2019/11/21 21:04, Barak Sason Rofman ??:
>
> I see two design / implementation problems with that mechanism:
>
>    1.
>
>    The mutex that guards the log file is likely under constant contention.
>    2.
>
>    The fact that each worker thread perform the IO by himself, thus
>    slowing his "real" work.
>
>
> Initial tests, done by *removing logging from the regression testing,
> shows an improvement of about 20% in run time*. This indicates we?re
> taking a pretty heavy performance hit just because of the logging activity.
>
> Hi Barak Sason Rofman.  Amazing perf improvement! Could show me the detail
> test method ?
>
> Thanks
>
>     -Xie
>
> In addition to these problems, the logging module is due for an upgrade:
>
>    1.
>
>    There are dozens of APIs in the logger, much of them are deprecated -
>    this makes it very hard for new developers to keep evolving the project.
>    2.
>
>    One of the key points for Gluster-X, presented in October at
>    Bangalore, is the switch to a structured logging all across gluster.
>
>
-- 
*Barak Sason Rofman*

Gluster Storage Development

Red Hat Israel <https://www.redhat.com/>

34 Jerusalem rd. Ra'anana, 43501

bsasonro at redhat.com <adi at redhat.com>    T: *+972-9-7692304*
M: *+972-52-4326355*
<https://red.ht/sig>
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.gluster.org/pipermail/gluster-users/attachments/20191122/f0e6d1b7/attachment-0001.html>

? 2019/11/22 17:43, Barak Sason Rofman ??:
> Thank you for your input Atin and Xie Changlong.
>
> Regarding log ordering - my initial thought was to do it offline using 
> a dedicated too. Should be straight forward, as the logs have time 
> stamp composed of seconds and microseconds, so ordering them using 
> this value is definitely possible.
> This is actually one of the main reasons I wanted to bring this up for 
> discussion - will it be fine with the community to run a dedicated 
> tool to reorder the logs offline?
> Reordering the logs offline will allow us to gain the most performance 
> improvement, as keeping the logs order online will have some cost 
> (probably through stronger synchronization).
> Moreover, we can take log viewing one step further and maybe create 
> some GUI system (JAVA based?) to view and handle logs (e.g. one window 
> to show the combined order logs, other windows to show logs per thread 
> etc').
>
> Regarding the test method - my initial testing was done by removing 
> all logging from regression. Modifying the method "skip_logging"
to
> return 'true' in all cases seems to remove most of the logs (though
> not all, "to be on the safe side", really removing all logging
related
> methods is probably even better).

Thanks for sharing, i'll go back to your method and do some perf test : )

> As regression tests use mostly single-node tests, some additional 
> testing was needed. I've written a couple of very basic scripts to 
> create large number of files / big files, read / write to / from them, 
> move them around and perform some other basic functionality.
> I'd actually be glad to test this in some 'real world' use
cases - if
> you have specific use cases that you use frequently, we can model them 
> and benchmark against - this will likely offer an even more accurate 
> benchmark.
>
> On Fri, Nov 22, 2019 at 7:27 AM Xie Changlong <zgrep at 139.com 
> <mailto:zgrep at 139.com>> wrote:
>
>
>     ? 2019/11/21 21:04, Barak Sason Rofman ??:
>>
>>     I see two design / implementation problems with that mechanism:
>>
>>     1.
>>
>>         The mutex that guards the log file is likely under constant
>>         contention.
>>
>>     2.
>>
>>         The fact that each worker thread perform the IO by himself,
>>         thus slowing his "real" work.
>>
>>
>>     Initial tests, done by *removing logging from the regression
>>     testing, shows an improvement of about 20% in run time*. This
>>     indicates we?re taking a pretty heavy performance hit just
>>     because of the logging activity.
>>
>>
>     Hi Barak Sason Rofman.? Amazing perf improvement! Could show me
>     the detail test method ?
>
>     Thanks
>
>     ??? -Xie
>
>>     In addition to these problems, the logging module is due for an
>>     upgrade:
>>
>>     1.
>>
>>         There are dozens of APIs in the logger, much of them are
>>         deprecated - this makes it very hard for new developers to
>>         keep evolving the project.
>>
>>     2.
>>
>>         One of the key points for Gluster-X, presented in October at
>>         Bangalore, is the switch to a structured logging all across
>>         gluster.
>>
>
>
> -- 
> *Barak Sason Rofman*
>
> Gluster Storage Development
>
> Red Hat?Israel <https://www.redhat.com/>
>
> 34 Jerusalem rd. Ra'anana, 43501
>
> bsasonro at redhat.com <mailto:adi at redhat.com> ?T:
_+972-9-7692304_
> M: _+972-52-4326355_
>
> <https://red.ht/sig>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.gluster.org/pipermail/gluster-users/attachments/20191122/6bc92281/attachment.html>

On Fri, Nov 22, 2019 at 11:45 AM Barak Sason Rofman <bsasonro at
redhat.com>
wrote:
> Thank you for your input Atin and Xie Changlong.
>
> Regarding log ordering - my initial thought was to do it offline using a
> dedicated too. Should be straight forward, as the logs have time stamp
> composed of seconds and microseconds, so ordering them using this value is
> definitely possible.
> This is actually one of the main reasons I wanted to bring this up for
> discussion - will it be fine with the community to run a dedicated tool to
> reorder the logs offline?
> Reordering the logs offline will allow us to gain the most performance
> improvement, as keeping the logs order online will have some cost (probably
> through stronger synchronization).
> Moreover, we can take log viewing one step further and maybe create some
> GUI system (JAVA based?) to view and handle logs (e.g. one window to show
> the combined order logs, other windows to show logs per thread etc').
>
If you need an external tool (please not Java - let's not add another
language to the project), you might as well move to binary logging.
I believe we need to be able to do this sort using Linux command line tools
only.
>
> Regarding the test method - my initial testing was done by removing all
> logging from regression. Modifying the method "skip_logging" to
return
> 'true' in all cases seems to remove most of the logs (though not
all, "to
> be on the safe side", really removing all logging related methods is
> probably even better).
>
This is not a fair comparison:
1. The regression tests are running with debug log
2. Not logging at all != replacing the logging framework - the new one will
have its own overhead as well.
3. I believe there's a lot of code that is not real life scenarios there -
such as dumping a lot of data there (which causes a lot of calls to
inode_find() and friends - for example).
Y.

As regression tests use mostly single-node tests, some additional
testing
> was needed. I've written a couple of very basic scripts to create large
> number of files / big files, read / write to / from them, move them around
> and perform some other basic functionality.
> I'd actually be glad to test this in some 'real world' use
cases - if you
> have specific use cases that you use frequently, we can model them and
> benchmark against - this will likely offer an even more accurate benchmark.
>
> On Fri, Nov 22, 2019 at 7:27 AM Xie Changlong <zgrep at 139.com>
wrote:
>
> >
> > ? 2019/11/21 21:04, Barak Sason Rofman ??:
> >
> > I see two design / implementation problems with that mechanism:
> >
> >    1.
> >
> >    The mutex that guards the log file is likely under constant
contention
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.gluster.org/pipermail/gluster-users/attachments/20191122/b47524ab/attachment.html>

On 22/11/19 3:13 pm, Barak Sason Rofman wrote:
> This is actually one of the main reasons I wanted to bring this up for 
> discussion - will it be fine with the community to run a dedicated 
> tool to reorder the logs offline?
I think it is a bad idea to log without ordering and later relying on an 
external tool to sort it.? This is definitely not something I would want 
to do while doing test and development or debugging field issues.? 
Structured logging? is definitely useful for gathering statistics and 
post-processing to make reports and charts and what not,? but from a 
debugging point of view, maintaining causality of messages and working 
with command line text editors and tools on log files is important IMO.

I had a similar concerns when? brick multiplexing feature was developed 
where a single log file was used for logging all multiplexed bricks' 
logs.? So much extra work to weed out messages of 99 processes to read 
the log of the 1 process you are interested in.

Regards,
Ravi