Student Login

A Nifty Python Logging Trick

Python has this wonderful, magnificent, terrifying logging module. You ought to be using it, and if you're like me, you dragged your feet for years before you started to learn how it worked.

Because it's this big, complex, intimidating beast. I still don't use it enough. (Note to self: make sure I use it today.)

Here's one tip I figured out:

One of the whole points of logging is to pepper your code with logging statements of different severities - debug, info, warning, error, and critical. You do this without restraint, because you can always crank the logging threshold up or down. When everything's running smoothly in production, you tune out the details you don't care about: 

  1. # We only want to see WARNINGs and higher.

  2. import logging

  3. logging.basicConfig(level=logging.WARNING)

  4. 

  5. # Later in your code:

  6. logging.debug('Adding user %s to group %s',

  7.               user.name, new_group)

  8. if not user.is_current():

  9.     logging.warning('User %s owes membership dues', user.name)

This will show the warning, but not the debug message. Later, when you're troubleshooting some tricky bug, you change the log level threshold: 

  1. # Show me everything!

  2. import logging

  3. logging.basicConfig(level=logging.DEBUG)

Now, imagine you change this line during development. That means you have to remember to un-change it before you merge and deploy. Raise your hand if you've ever made a temporary hack of a change to your code, with no intention of committing it... but you did anyway. Yeah, me too:

  1. # An actual line I wrote once, just so I could study

  2. # the stack trace at that point in the code:

  3. 

  4. raise Exception("BOOM!")

  5. 

  6. # 1) Yes, I accidentally committed it.

  7. # 2) No, neither the unit tests nor the code review caught it.

  8. # 3) Yes, it got deployed.

  9. # 4) No, I'm not proud.

That's the situation we have with log levels. During production, we normally won't want it set below WARNING. During development, we might rather it be set to INFO, and sometimes DEBUG. How do we safely pull this off?

Simple: use an environment variable. This is something you can do in every operating system - at least, the ones people actually use to write code. You read them in your Python program via os.environ - a simple Python dictionary.

So let's write our code to use the production threshold of WARNING by default - but we can easily override it in the environment:

  1. import logging

  2. import os

  3. 

  4. LOGLEVEL = os.environ.get('LOGLEVEL', 'WARNING').upper()

  5. logging.basicConfig(level=LOGLEVEL)

This code reads an environment variable called LOGLEVEL. You can pick a different name, of course; if my app is called FooBar, I might call it FOOBAR_LOGLEVEL. You can often set it in your IDE, or just in the OS (Google will tell you how.)

Now I can set that variable to "debug" or "DEBUG" or "DeBuG" to enable to debug messages on my machine. But - and this is the important part - not on production. It's safe.

And that's how I make my code a little less likely to cause surprise grief when it's deployed.

White Paper Bootcamp