goodboy
The lurkerz want hipper logging..
After my (yet again) completely in vain attempts to get code review of #243, the lurkers were kind enough to chime in with all sorts of neat ideas for how to do a better tracing system, re logging.
In particularly @parity3 made the following set of comments which give guide to some approaches that might not stray so far from the stdlib's toolset:
- a note on something i didn't know: you can use extra flags which can also be filtered by consumer code
- a comment on external approaches that diverge from the stdlib which includes some example code for using custom filters to trace (previously) said flagged log msgs:
They can't resist trying to make things "easier" than the standard lib and therefore breaking an API everyone already knows.
-
finished off with a nice approaches summary:
- Flat exclusive type (ie custom loglevel)
- Tags-style (LogRecord attributes)
- Log category hierarchy (log.name)
@salotz also piped in, notably with:
The structured logs really screw up stack traces and stepping around in debugging.
so I guess current consensus is structured logging es no bueno.
Happy to lurk on over here. Re: the code review, I don't have enough time to really dig in so all I can do is yap away on my opinions on logging in general. And here I go again.
I have another opinion on logging which could be perhaps unpopular, which is to make all logging synchronous. Assuming that your logs aren't happening very often, this shouldn't be a huge sacrifice in performance, and gives you more determinism.
I bring this up because I've seen a couple of occasions where people are putting logs into a queue and using either threading or another async task to write to a log file or worse: stream them somewhere. My opinion is that it's fine if you want to stream them, but do it in another process. Then you can avoid any graceful shutdown headaches at least when it comes to logging.
I love runit's svlogd to further offload logging logic (rotations, pipeline-processing) from the core python process. I have not tried this yet because it's a somewhat high barrier to entry in terms of scaffolding/setup during the launch phase of your app. It is heavily "line-based" so you may need to devise a strategy to munge the multi-line log entries. Not to mention you probably need a designated inherited file handle (do not use stdout/stderr) because otherwise you may be battling other dependent libs that blindly print things or use those standard pipes for other purposes.
As another "helper" outside of the python code process, I have a "pylog.py" module that runs under a runit "/log" context (runit spawns this and pipes any output from the main process into this log process) from which I can add "process started with args..." and "process finished" log lines, as well as prefix the lines time and/or a service prefix, etc.
To summarize:
- logging should ALWAYS be synchronous; prevents headaches and worth the sacrifice
- push any log processing / asynchronicity out to other processes
- see runit's svlogd and their runsv /log dir structure for inspiration
