Barak Sason Rofman
2019-Nov-21 13:04 UTC
[Gluster-users] Modifying gluster's logging mechanism
Hello Gluster community, My name is Barak and I?ve joined RH gluster development in August. Shortly after my arrival, I?ve identified a potential problem with gluster?s logging mechanism and I?d like to bring the matter up for discussion. The general concept of the current mechanism is that every worker thread that needs to log a message has to contend for a mutex which guards the log file, write the message and, flush the data and then release the mutex. 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. 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. Given these points, I believe we?re in a position that allows us to upgrade the logging mechanism by both switching to structured logging across the project AND replacing the logging system itself, thus ?killing two birds with one stone?. Moreover, if the upgrade is successful, the new logger mechanism might be adopted by other teams in Red Hat, which lead to uniform logging activity across different products. I?d like to propose a logging utility I?ve been working on for the past few weeks. This project is still a work in progress (and still much work needs to be done in it), but I?d like to bring this matter up now so if the community will want to advance on that front, we could collaborate and shape the logger to best suit the community?s needs. An overview of the system: The logger provides several (number and size are user-defined) pre-allocated buffers which threads can 'register' to and receive a private buffer. In addition, a single, shared buffer is also pre-allocated (size is user-defined). The number of buffers and their size is modifiable at runtime (not yet implemented). Worker threads write messages in one of 3 ways that will be described next, and an internal logger threads constantly iterates the existing buffers and drains the data to the log file. As all allocations are allocated at the initialization stage, no special treatment it needed for "out of memory" cases. The following writing levels exist: 1. Level 1 - Lockless writing: Lockless writing is achieved by assigning each thread a private ring buffer. A worker threads write to that buffer and the logger thread drains that buffer into a log file. In case the private ring buffer is full and not yet drained, or in case the worker thread has not registered for a private buffer, we fall down to the following writing methods: 1. Level 2 - Shared buffer writing: The worker thread will write it's data into a buffer that's shared across all threads. This is done in a synchronized manner. In case the private ring buffer is full and not yet drained AND the shared ring buffer is full and not yet drained, or in case the worker thread has not registered for a private buffer, we fall down to the last writing method: 1. Level 3 - Direct write: This is the slowest form of writing - the worker thread directly write to the log file. The idea behind this utility is to reduce as much as possible the impact of logging on runtime. Part of this reduction comes at the cost of having to parse and reorganize the messages in the log files using a dedicated tool (yet to be implemented) as there is no guarantee on the order of logged messages. The full logger project is hosted on: https://github.com/BarakSason/Lockless_Logger For project documentation visit: https://baraksason.github.io/Lockless_Logger/ I thank you all for reading through my suggestion and I?m looking forward to your feedback, -- *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/20191121/191a25c8/attachment.html>
Atin Mukherjee
2019-Nov-22 03:20 UTC
[Gluster-users] [Gluster-devel] Modifying gluster's logging mechanism
This is definitely a good start. In fact the experiment you have done which indicates a 20% improvement of run time perf with out logger does put this work for a ?worth a try? category for sure. The only thing we need to be mindful here is the ordering of the logs to be provided, either through a tool or the logger itself taking care of it. On Thu, 21 Nov 2019 at 18:34, Barak Sason Rofman <bsasonro at redhat.com> wrote:> Hello Gluster community, > > My name is Barak and I?ve joined RH gluster development in August. > Shortly after my arrival, I?ve identified a potential problem with > gluster?s logging mechanism and I?d like to bring the matter up for > discussion. > > The general concept of the current mechanism is that every worker thread > that needs to log a message has to contend for a mutex which guards the log > file, write the message and, flush the data and then release the mutex. > 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. > > 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. > > > Given these points, I believe we?re in a position that allows us to > upgrade the logging mechanism by both switching to structured logging > across the project AND replacing the logging system itself, thus ?killing > two birds with one stone?. > > Moreover, if the upgrade is successful, the new logger mechanism might be > adopted by other teams in Red Hat, which lead to uniform logging activity > across different products. > > I?d like to propose a logging utility I?ve been working on for the past > few weeks. > This project is still a work in progress (and still much work needs to be > done in it), but I?d like to bring this matter up now so if the community > will want to advance on that front, we could collaborate and shape the > logger to best suit the community?s needs. > > An overview of the system: > > The logger provides several (number and size are user-defined) > pre-allocated buffers which threads can 'register' to and receive a private > buffer. In addition, a single, shared buffer is also pre-allocated (size is > user-defined). The number of buffers and their size is modifiable at > runtime (not yet implemented). > > Worker threads write messages in one of 3 ways that will be described > next, and an internal logger threads constantly iterates the existing > buffers and drains the data to the log file. > > As all allocations are allocated at the initialization stage, no special > treatment it needed for "out of memory" cases. > > The following writing levels exist: > > 1. > > Level 1 - Lockless writing: Lockless writing is achieved by assigning > each thread a private ring buffer. A worker threads write to that buffer > and the logger thread drains that buffer into a log file. > > In case the private ring buffer is full and not yet drained, or in case > the worker thread has not registered for a private buffer, we fall down to > the following writing methods: > > 1. > > Level 2 - Shared buffer writing: The worker thread will write it's > data into a buffer that's shared across all threads. This is done in a > synchronized manner. > > In case the private ring buffer is full and not yet drained AND the shared > ring buffer is full and not yet drained, or in case the worker thread has > not registered for a private buffer, we fall down to the last writing > method: > > 1. > > Level 3 - Direct write: This is the slowest form of writing - the > worker thread directly write to the log file. > > The idea behind this utility is to reduce as much as possible the impact > of logging on runtime. Part of this reduction comes at the cost of having > to parse and reorganize the messages in the log files using a dedicated > tool (yet to be implemented) as there is no guarantee on the order of > logged messages. > > The full logger project is hosted on: > https://github.com/BarakSason/Lockless_Logger > > For project documentation visit: > https://baraksason.github.io/Lockless_Logger/ > > I thank you all for reading through my suggestion and I?m looking forward > to your feedback, > -- > *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> > _______________________________________________ > > Community Meeting Calendar: > > APAC Schedule - > Every 2nd and 4th Tuesday at 11:30 AM IST > Bridge: https://bluejeans.com/441850968 > > > NA/EMEA Schedule - > Every 1st and 3rd Tuesday at 01:00 PM EDT > Bridge: https://bluejeans.com/441850968 > > Gluster-devel mailing list > Gluster-devel at gluster.org > https://lists.gluster.org/mailman/listinfo/gluster-devel > > ----Atin -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.gluster.org/pipermail/gluster-users/attachments/20191122/b8ee8168/attachment.html>
Xie Changlong
2019-Nov-22 05:26 UTC
[Gluster-users] [Gluster-devel] Modifying gluster's logging mechanism
? 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. >-------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.gluster.org/pipermail/gluster-users/attachments/20191122/328448f3/attachment.html>
Amar Tumballi
2019-Nov-27 02:14 UTC
[Gluster-users] [Gluster-devel] Modifying gluster's logging mechanism
Hi Barak, My replies inline. On Thu, Nov 21, 2019 at 6:34 PM Barak Sason Rofman <bsasonro at redhat.com> wrote:> Hello Gluster community, > > My name is Barak and I?ve joined RH gluster development in August. > Shortly after my arrival, I?ve identified a potential problem with > gluster?s logging mechanism and I?d like to bring the matter up for > discussion. > > The general concept of the current mechanism is that every worker thread > that needs to log a message has to contend for a mutex which guards the log > file, write the message and, flush the data and then release the mutex. > 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. > >Both above points are true, and can have an impact when there is lot of logging. While some of us would say we knew the impact of it, we had not picked this up as a priority item to fix for below reasons. * First of all, when we looked at log very early in project's life, our idea was based mostly on kernel logs (/var/log/messages). We decided, as a file-system, because it is very active with I/Os and should run for years together without failing, there should be NO log messages when the system is healthy, which should be 99%+ time. * Now, if there are no logs when everything is healthy, and most of the things are healthy 99% of the time, naturally the focus was not 'performance' of logging infra, but the correctness. This is where, the strict ordering through locks to preserve the timestamps of logs, and have it organized came by.> 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. > >That is interesting observation. For this alone, can we have an option to disable all logging during regression? That would fasten up things for normal runs immediately.> 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. > > >+1> Given these points, I believe we?re in a position that allows us to > upgrade the logging mechanism by both switching to structured logging > across the project AND replacing the logging system itself, thus ?killing > two birds with one stone?. > > Moreover, if the upgrade is successful, the new logger mechanism might be > adopted by other teams in Red Hat, which lead to uniform logging activity > across different products. > >This, in my opinion is a good reason to undertake this activity. Mainly because we should be having our logging infra similar with other tools, and one shouldn't be having a learning curve to understand gluster's logging.> I?d like to propose a logging utility I?ve been working on for the past > few weeks. > This project is still a work in progress (and still much work needs to be > done in it), but I?d like to bring this matter up now so if the community > will want to advance on that front, we could collaborate and shape the > logger to best suit the community?s needs. > > An overview of the system: > > The logger provides several (number and size are user-defined) > pre-allocated buffers which threads can 'register' to and receive a private > buffer. In addition, a single, shared buffer is also pre-allocated (size is > user-defined). The number of buffers and their size is modifiable at > runtime (not yet implemented). > > Worker threads write messages in one of 3 ways that will be described > next, and an internal logger threads constantly iterates the existing > buffers and drains the data to the log file. > > As all allocations are allocated at the initialization stage, no special > treatment it needed for "out of memory" cases. > > The following writing levels exist: > > 1. > > Level 1 - Lockless writing: Lockless writing is achieved by assigning > each thread a private ring buffer. A worker threads write to that buffer > and the logger thread drains that buffer into a log file. > > In case the private ring buffer is full and not yet drained, or in case > the worker thread has not registered for a private buffer, we fall down to > the following writing methods: > > 1. > > Level 2 - Shared buffer writing: The worker thread will write it's > data into a buffer that's shared across all threads. This is done in a > synchronized manner. > > In case the private ring buffer is full and not yet drained AND the shared > ring buffer is full and not yet drained, or in case the worker thread has > not registered for a private buffer, we fall down to the last writing > method: > > 1. > > Level 3 - Direct write: This is the slowest form of writing - the > worker thread directly write to the log file. > > The idea behind this utility is to reduce as much as possible the impact > of logging on runtime. Part of this reduction comes at the cost of having > to parse and reorganize the messages in the log files using a dedicated > tool (yet to be implemented) as there is no guarantee on the order of > logged messages. >This is agreeable compromise for reducing load on running system. As, most of the times, logs are used for debugging, and are mostly debugged in isolation after the event happens, if there exists a tool to get things ordered, then it should be fine. I am in agreement with Sankarshan, who responded in another thread about tools like EFK/ELK stack for centralized logging. By moving to centralized logging, and having proper structure for logging, the initial goals we had wouldn't be broken, and we will have better performance even when we are logging in DEBUG mode.> The full logger project is hosted on: > https://github.com/BarakSason/Lockless_Logger > > For project documentation visit: > https://baraksason.github.io/Lockless_Logger/ > >Please make sure, we have minimum dependency on this project, and also the install steps are easy for your project. One of the reasons Gluster succeeded is because it is very easy to install (and uninstall), without much dependencies. I personally would like to keep that behavior same. While developing, at least for couple of releases after this gets used, we need to have current logging structure also as an option. So, there would be confidence to try new thing. Regards, Amar <https://baraksason.github.io/Lockless_Logger/>I thank you all for reading> through my suggestion and I?m looking forward to your feedback, > -- > *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> > _______________________________________________ > > Community Meeting Calendar: > > APAC Schedule - > Every 2nd and 4th Tuesday at 11:30 AM IST > Bridge: https://bluejeans.com/441850968 > > > NA/EMEA Schedule - > Every 1st and 3rd Tuesday at 01:00 PM EDT > Bridge: https://bluejeans.com/441850968 > > Gluster-devel mailing list > Gluster-devel at gluster.org > https://lists.gluster.org/mailman/listinfo/gluster-devel > >-------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.gluster.org/pipermail/gluster-users/attachments/20191127/3c572f74/attachment.html>