Octoprint: [Request] Use asynchronous logging

[FormerLurker]

Occasionally the logger takes a long time to output (maybe 1 in every1000 or so lines). I have seen it take from 0.25 to 1 second. I am pretty sure it's the logger, because when I disable it the problem goes away.

I have implemented the following for my logging (pseudoish coding):

Logging_Executor = concurrent.futures.ThreadPoolExecutor(max_workers=1)

def log_info(message):
    Logging_Executor.submit(self._logger.info, message)

This seems to fix my issue completely, and was pretty simple to implement and may be transferable to OctoPrint.

Thanks!

[foosel]

Done per the above commit. Already on maintenance, soon devel, will be part of 1.3.8.

[FormerLurker]

Wow, that was fast! That is a much better way to implement this. I actually started with something similar but decided to go with the path of least resistance :)

Hopefully this will reduce the number of mysterious issues you receive. Here is a photo containing 3 benchys. From left to right: No logging, Lots and lots of logging (more than usual for sure), lots and lots and lots of async logging.

[FormerLurker]

Going to close this issue since it has been scheduled to be added. I think this will be a nice feature, thanks for adding it!

[foosel]

Quick update on this: will be released with OctoPrint 1.3.9, 1.3.8 was just turned into a hotfix release.

[FormerLurker]

Thanks for letting me know.