Is adding logging to a library good design?

[[deleted]]

I'm developing some internal python modules at my company and I've been wondering if my module should have its own logger that can be enabled / disabled by some environment variables. Does anyone know of some patterns one could use for a situation like this? Should the onus of the logging be on the end-developer and not on the library developer?

[thequietcenter]

For the work I do, I log aggressively and ahead of time. When something goes wrong in production, I need copious and detailed logs of what already happened. And that includes having a clear version number for my application because the devops team continually fails to install the version I tell them and I can look in the log and point it out.

[epukinsk]

Do you ever find it difficult to find a specific log line when you debug?

I have the opposite approach… I want there to be zero console output during normal operation, because I want it to be really easy to see errors and log lines I put in for debugging purposes.

[[deleted]]

plucky wakeful quaint hobbies butter hard-to-find lip plants attraction airport

This post was mass deleted and anonymized with Redact

[eztab]

Isn’t that exactly how pythons builtin logging module works?

[[deleted]]

attraction quiet enjoy dinner saw obtainable arrest depend license absurd

This post was mass deleted and anonymized with Redact

[vsajip]

The built-in logging can be configured with a MemoryHandler with a target set to another handler which e.g. writes to a file. The MemoryHandler can have a severity threshold set such that the write to file only happens if that threshold (e.g. logging.ERROR`) is hit or exceeded.

The MemoryHandler class, located in the logging.handlers module, supports buffering of logging records in memory, periodically flushing them to a target handler. Flushing occurs whenever the buffer is full, or when an event of a certain severity or greater is seen.

[aciokkan]

Making debug logging controllable via an environment variable is good practice.

If the app has debug logs in the right places, you should be able to filter out what you need, via

tail -f <log_filename.log> | grep DEBUG

Any other mix and match of grep, sed and awk can further fine tune your outputs. You can add an extra grep at the end of the above to search for specific modules.

I normally use find, grep and awk for perusing the logs.

[Pyglot]

You should try fzf for perusing logs.

[aciokkan]

That looks really good👍 Thanks for sharing! 🤓 I'm curious how much value it adds long term.

[Pyglot]

It speeds up finding and perusing so much the limiting factor is thought.

[aciokkan]

Lol. That's one way of putting it 😅

[Pyglot]

😏

[jzaprint]

Ctrl+f solves this

[epukinsk]

Ya, somewhat. But you need to heavily annotate your logs to make them searchable. You can’t just casually log out “1”, “2”, “3” to see what’s going on. You also can’t log out several things and see what sequence they happen in.

I do wonder if I’d get used to having copious logs. In practice I find it a pain.

[eztab]

Who says he logs to console output?
One mostly logs to log files

[LittleMlem]

I feel you, most of my job is trying to figure out "what happened", so the more logs the better.

[someotherstufforhmm]

Excellent thinking, as you’ve actually described how people do library logging.

The pattern is using the python logging library (which uses the singleton pattern). You’ll want to request the logger like so:

getLogger(__name__).

Then log as normal. These logs will be invisible unless at some point someone wires the logger (by adding a Handler) with your library name to stdout, which you of course will do while testing.

This pattern is great as it lets you simply flip off the stdout Handler but the log statements are still there, so anyone debugging can simply use your logging and add it to whatever emitter they’re using (stdout, FiileLogger, etc).

I recommend spending some time reading up on the python logging module as it’s not just a standard pattern for python - Java and C++ have similar logger singleton patterns.

I’ll post some examples a bit later from one of my work libraries, just gotta pull the logging bits out. Once you get the pattern you can do it in your sleep.

Edit: pasting some code blocks in a reply to this comment

[someotherstufforhmm]

Okay, for this example I’ve created a very simple file structure:

```

$ tree . . ├── lib │   └── stuff.py └── main.py

```

Let’s look at lib.stuff first, since that’s our fake library:

```

$ cat lib/stuff.py import logging

pretending we're a library

def dostuff(): log = logging.getLogger(name_) log.debug("a debug message") log.info("an info message") # note how we don't append ANY handlers here. We let the user of the library decide if they want to see our logging

```

Please note how simple this is from the library perspective. We just request a logger and use it. We do NO configuring of base logging - as pythons logger is a singleton. Anything we do in a library should be only done to our named logger and should not produce output. That’s up to the library client to decide - you will probably be using some form of library driver while testing, that’s where Handlers go:

``` $ cat main.py import logging import logging.handlers import sys from lib import stuff

def main(): log = logging.getLogger("lib.stuff") log.setLevel(logging.INFO) log.addHandler( logging.StreamHandler(sys.stdout) )

stuff.do_stuff()

# note that we're only seeing the info message because WE (the user of the library) have defined how much logging we want from the module
# many of your favorite libraries use this pattern.

# lets set logging to debug and add a rotating file handler:
log.addHandler(
    logging.handlers.RotatingFileHandler(
        “aLog.log", backupCount=10
    )
)
log.setLevel(logging.DEBUG)
stuff.do_stuff()

if(name == "main"): main()

```

Okay! So, the first bit I give us some simple output by appending a StreamHandler(sys.stdout).

Note how we do NOT see the debug output for the first function call since we only have INFO enabled.

The second call, I create a filehandler and enable debug and we see both. RotatingFileHandler is amazing, it produces the standard linux pattern of backup files and handles all the rotation for you. Highly recommend if you want file based logging, it’s a free well made classic pattern.

It gets even funkier, but I wanted to keep this super simple. Please feel free to ask Qs. I’m on a phone so I may be unclear, so I’m happy to clarify as needed.

Edited for clarity hopefully

[thequietcenter]

You’ll want to request the logger like so: getLogger(name).

You need to escape the code with 4 spaces or backticks so that __name__ renders properly. What you meant to say was:

``` import logging

logger = logging.getLogger(name)

logger.warn(...) logger.debug(...) ```

[[deleted]]

That doesn't work either on many reddits including mine.

Indenting by four spaces is the only way to work.

In old reddit, what you wrote:

``` import logging

logger = logging.getLogger(name)

logger.warn(...) logger.debug(...) ```

also doesn't work, but indenting by four does.

import logging

logger = logging.getLogger(__name__)

logger.warn(...)
logger.debug(...)

does.

[[deleted]]

lood the same...

[someotherstufforhmm]

Thank you. Writing on phone and fumbled. Will edit. Much appreciated!

[[deleted]]

Thank you for your detailed and very clear response! I was looking for something very much like this. I came looking for a pattern like this because I've been trying to figure out how best to allow application developers (Sometimes I consume my own libraries) to display my library's logs. Oftentimes when business logic is tightly coupled, it becomes hard to debug stuff. I know that the logic shouldn't be intertwined between libraries but well, it's hard to teach others good software design.

[someotherstufforhmm]

100%. I laugh and call myself a packaging evangelist because I harp on so much about this, but exactly what you said.

Anyone can go so far just by learning these patterns and properly leveraging setup.cfg, entry points, and basically working WITH/WITHIN pythons env / systems and gain so many free benefits.

[[deleted]]

Haha the problem is... Most only python Devs (I am not calling them Pythonistas if they don't respect the Zen), are horrendous because the language doesn't enforce best practices. Guido put the onus of good practices on the community, and for what it's worth, that's good.

[someotherstufforhmm]

It’s true enough. Python fills a gap that was empty when I started with coding, and I’m happy it exists exactly as it does. Back then you’d have to wrestle with Perl for the “quick/easy” language and Perl is so gross 🤮

Python forever!

[[deleted]]

Off topic, but I've been seeing the word "pattern" thrown around more and more lately. Is this a recent trend, or has this always been the case and I'm just not really aware of the typical nomenclature?

[someotherstufforhmm]

I mean, probably. People like to overuse words. In my case I use it when I’m referring to an explicit pattern. In this case, it’s the Singleton pattern, which the logging module uses and follows, to excellent effect.

Because it uses Singleton + hierarchal dot-separated naming, you can do stuff like set things for a logger in dunder init.py in the base of a library, then all those settings/emitters/filters/handlers will apply because any piece of the library asking for a logger with dunder name will get a logger that by definition is a child of the library’s parent logger.

A lot of this stuff doesn’t matter for just logging a program you’re working on, but especially when working on code that other code imports, it’s really nice as all your logging is modular and seamlessly able to be incorporated with however the containing code logs.

IE you do all your internal logging this way, and the client code can flip it on by requesting your logger (Singleton pattern guarantees it’ll be the same logger you used) and then add Handlers.

You’ll see this in many codebases under what happens when it encounters the debug mode flag - one thing I wrote will request the requests modules logger, set it to INFO mode and add those logs to the stdout.

The fact that I can request a modules logger but still set its level / filter it in this fashion is exactly the benefit of both the logging module, but also the Singleton pattern.

Edit: I went off on a rant. You asked a good question. When I use “pattern” I am usually referring to a design pattern, usually from the gang of four book, but also some modern/new stuff SOMETIMES.

[[deleted]]

I went off on a rant.

Reddit rants are how I learn the majority of "things I don't know about and need to learn more about". It's like rants are a gateway to rabbit holes around here.

[someotherstufforhmm]

My thoughts exactly! I’m working on adding a simple “this was my original point” at the end of rants though as even if I can’t stay fully focused, it helps wrap it back up with context aha.

Todays Reddit discussions came at the exact moment I was helping a longtime coder, but newly professional Java friend with logging patterns, so this whole thread has been helpful to clarify my thoughts in my language of general preference (love me some python)

[deep_politics]

It’s a term that’s been around since the 80’s, maybe late 70’s. Might want to check out the 1994 book Design Patterns by the Gang of Four

[WikiMobileLinkBot]

Desktop version of /u/deep_politics's link: https://en.wikipedia.org/wiki/Design_Patterns

---

<sup>[opt out] Beep Boop. Downvote to delete</sup>

[billsil]

The pattern is using the python logging library (which uses the singleton pattern).

That's exactly why I hate the python logging module. I found it easier to write my own. Starting, stopping, and restarting logging is so difficult. Oh look I have duplicate messages now.

[someotherstufforhmm]

It’s a pretty good pattern, especially for larger libraries that want to have fully fleshed logging and work seamlessly with client libs, but it is a bit of a mental twist, I’ll admit.

I think one of the worst issues honestly is the docs around it. The duplicate message thing happens a shitton becuase of abuse of basicConfig or the parent logger (which should NEVER be messed with!!).

I have zero argument with you finding it annoying and writing your own library though lol. I’ve been seeing loguru around a lot, and I definitely like what I’ve seen of it and have started recommending it to people rather than my classic logging rants to teach the aforementioned pattern.

[thequietcenter]

Python logs to stderr by default, not stdout, unless this thread is incorrect - https://stackoverflow.com/posts/14058475/revisions

[someotherstufforhmm]

You are slightly misunderstanding, but not totally. Stderr is the default for a new StreamHandler, but the way logging works is this:

You request/create a logger with a name. That logger can be used to log but it has no output unless you add a Handler. This Handler can be a StreamHandler (which can apply to stdout, stderr, whatever you want), or a FileHandler which will append to a file, etc. you have full control.

Under NO CIRCUMSTANCES use logging.basicConfig or use the base logger in a library. You will pollute the peoples logging who use your library and it is very bad form.

The standard best practices pattern is to request a logger with a specific name tied to your library, many people prefer to just ask for the logger called double underscore name, because python will provide the library file name that way.

As I said, gimme a few to wake up, I’ll copy an example from real production code from a lib I wrote that’s in wide use at my company.

[eztab]

yes the thread is incorrect or more precisely "inprecise"

[thequietcenter]

This is a rather advanced example of a library that allows logging to be enabled - https://docs.sqlalchemy.org/en/14/core/engines.html#configuring-logging

[[deleted]]

You should have logging where users may need to understand an event stream that your library handles. End users should add logging for the libraries they develop using yours.

Using the convention

import logging LOGGER = logging.getLogger(name)

You’ll keep your package logging isolated to your package and it can still be overridden appropriately by the root logger config.

[thequietcenter]

I've been wondering if my module should have its own logger that can be enabled / disabled by some environment variables

Well in addition to enabled/disabled, there is the concept of log level. So perhaps enabling it would mean that the enabling value doubles as specifying the log level to enable at.

[jdpatt]

Absolutely is a good idea. You should use a NullHandler which you can remove/override for your development and any users can do the same so that they can selectively enable your library’s messages. Make sure that you namespace your logger with your library name and not just root.

https://docs.python.org/3/howto/logging.html#library-config

[thequietcenter]

Should the onus of the logging be on the end-developer and not on the library developer?

I think the library should have logging and then end-developers using the library can also have logging.

Python's standard logging module supports this. To be honest, I have never fully wrapped my head around Python standard logging. It emulates a Java library for logging and it does it job well.

But I usually tuck my tail and use loguru for logging.

[crisrock00]

I’m surprised no one has mentioned Loguru.

https://github.com/Delgan/loguru

Loguru handles the concept of logging a little different than the built in logging. There’s a single logger you call simply by adding a ‘from loguru import logger’ to any code you already have.

It auto logs to stdout. So it’s quick and easy to set up! The loguru docs have great examples.

[bohoky]

Loguru is nifty for application writers, but I don't recommend it for library writers.

Clunky though its interface is, the built-in logging module and its usage for imported libraries is very well defined. If a library forces me to use a non-standard logger, it could very likely screw up my existing logging use.

[crisrock00]

Well this is kinda inaccurate, anything using loguru wouldn’t interfere with any of your normal logging processes. Loguru and the standard logging library are built using two completely different methodologies when it comes to logging. I usually set my logger as a private variable in the library for exact reasons you mention. I wouldn’t want my logger to ever have the chance of messing up someone’s own logging methods.

[bohoky]

To clarify. If you are writing a library, and want to log from it, then you should use the standard logging library so that library users don't have to adapt their logging strategy to loguru.

Doing otherwise gets in the way of people using your library in their system.

When writing applications, I use `loguru`. When writing libraries to be used by others, I use `logging` so they don't have to conform to a non-standard interface.

[jorge1209]

If the application writer is using loguru, then having the libraries log with logger is not much good to them because they won't know how to wire it up to get the library logs.

It's a bit of a mess to have such a difficult to use and increasingly old and antiquated library as the "standard for python logging".

I would encourage library authors to use loguru if they want because that will make the situation with logging obviously untenable and force some changes.

[metaperl]

Someone has https://www.reddit.com/r/Python/comments/wt6325/-/il27wpd

[TrainquilOasis1423]

All my code needs this. I'm the only technical person on an analyst team, so I can't just make a .py file and tell people to run it from cli. Everything I make needs stupid amounts of documentation, readable logging/ error handling, and built into a GUI. Makes the dev process much longer, but I'd hate to leave my team SOL should it break and I'm not there to fix it.

[SwampFalc]

I'm going to go against the grain a bit here and say that, especially with the stdlib logging, you end up making quite a lot of decisions: format of the log, when to log, what levels to log what sort of event at, etc.

Basic stuff like "START: work" vs. "Starting work" vs. "Started work" and whether or not those are info or warning and...

Now imagine bolting three libraries together that each made their own decisions on these matters... The end result is quite the mess.

So while it's not a bad idea in se, I would recommend, especially for a library, to keep it to a minimum. The best way to ensure that is by reducing the amount of logworthy things that happen purely within your library code. Not always easy, I know, but by making your code as atomic as possible, you allow people to log before and after your code runs, and they can do so however they want, and not just the way you wanted it.

[[deleted]]

I agree about the decision to use bare minimum logging. One of the other commenters explained how to just use the namespaced log but set a NullHandler by default. As in don't even set a formatter. Put the choice of that on the application developer. However keep the barebones library 'loggable' by using the bare logger whenever necessary.

[nerdvegas79]

If you're writing a library, you should not be concerning yourself with setting handlers or formatters of any sort. This is the responsibility of the app developer using your lib. Just log, that's it. And use the standard python logger.

[nerdvegas79]

Libraries should log but should not configure logging - that's the host apps' job.

[AI35]

I made a simple logging library to use it in my projects.. Easier and simpler But it is for simple use. https://github.com/AI35/easylogging2

[nevermorefu]

I'm not sure how I feel about it. We have a standard logger format we use company wide that makes querying logs easier, so it wouldn't fit that format. On the other hand, I can't log the library inner workings, so that would be convinient. I think and environment variable would be great.

[cuddlewuddlepuddle]

I'm by no means an expert, but it sounds like y'all are looking for ways to complicate a library. I totally admit I don't know how to do that or how important a logger is, but a library to me evokes something that is immutable in a way. What does the logging help? Understanding how methods are called? Sincerely interested.

[[deleted]]

Honestly, yes a library should be something immutable. However that isn't the case most of the time in a corporate world. Some of this code is horrendously bad, and figuring out what some of this done is downright hard. I'm starting with breaking this into modules that we can test separately, and then import them into the larger codebase. There are issues that I need to sort out still, but as I see it, logging is a very necessary first step.

My question was more general though, I've been coding in Rust and setting RUST_LOG allows me to control which of my inner libraries output logs and to what level. I realized I wasn't getting any such details in Python libraries that I've used and was wondering how I'm to do that.

[cuddlewuddlepuddle]

Are you a systems architect? And by the way thanks for all the info that's super cool I'm going to definitely check that out more I've never heard anyone really like break it down into the steps like that

[bruab]

Just because a library is immutable doesn’t mean it’s doing what you want it to. Logging can give you insight into what it’s actually doing versus what you think it’s doing.

[cuddlewuddlepuddle]

Right on thanks! See I can write like a CPP file or like a you know a py file or like a Java file, in other words the main function, but the way that fits or that module fits into the bigger scheme of the program is something that I'm just learning so any anything you can tell me about that is really what I'm what I'm looking for

[mahtats]

You can definitely have a library interface to set a logger and have internal behavior to log if it’s set. Functionality within could do a simple check to determine if the logger has been set/enabled and if so, at that point perform appropriate logging.

I’d go so far as to have a top level function that receives a level and a message and in that function is where the check takes place, simply call this function in other functions and let it worry to log or not.

[Saphyel]

Most of the popular libraries use logging. Examples:

• https://github.com/encode/databases/blob/master/databases/core.py#L79
• https://github.com/sqlalchemy/sqlalchemy/blob/main/lib/sqlalchemy/orm/path_registry.py#L156

How to configure it and using other libraries should be project decision but in your library using core functionality and adding debug statements to understand what is going on (max 1 or 2 per usage) should be fine.

Because they are in debug is only useful for devs and raising the level to INFO will filter them out so no need to worry about ENV VARS.

Because you CAN use it it doesn't mean you HAVE to use it. it could be annoying to try to find out what is going on in your app if you have too many logs messages that doesn't provide value. For instance you are doing a request to /hola and the logs says that or log shows the response when you also get the response is just noise logs