Sharpen Your Code

Using the Right Tool (And a Note on Logging)

Coding can feel quite daunting—specially with the wealth of information out there to consume. Sometimes, as I stare at the code on my screen, I feel particularly stuck or unmotivated.

Analogy

During a summer break while in high school, I took an odd job of pine tree pruning.

Yeah, you read that right.

Pine tree pruning.

It involved carrying a 16-foot pole with a serrated blade at the end of it. Then, going down a line of pine trees, cutting all branches up to that height.

It was grueling. And paid terribly. I think it was something like 60 cents a tree, or something ridiculous. A thankless task for logging companies turning trees into lumber.

After my first day, I thought I did pretty well. I earned like $20 in approximately 8 hours. (That's a little over 30 trees, for those of you that are counting.)

One of the workers there was able to prune over 120 trees a day.

I was baffled.

The Obvious Correlation

What I found out after a couple of days is that the worker who was pruning lots of trees would sharpen his blade every night.

He was able to cut down branches with one swift movement, whereas I was spending time trying to literally saw off even smaller branches.

Yes, technique was important. But so was a sharp blade.

The tools you use to perform a task can be just as important as to how you accomplish that task.

Back to Development

I haven't posted on here for a little while because I've started a new side project.

Thankfully, I've taken a lot of lessons learned building my blog and transferred it over to my new project. But I still have a lot to learn.

I can't stress enough how important it is to be comfortable in your environment.

Secondly, take advantage of all the libraries in the Python ecosystem. A quick tip on those external tools...

As you start using different libraries, try to read the documentation, get to know the API, and really spend your time with them. It will help you a ton.

For me, that has meant getting comfortable with Beanie in order to interface with my MongoDB database.

Sharpen Your Own Tools

However, not all tools have to be external.

In Python, there are already a lot of built-in tools at your disposal. But if you don't sharpen them a bit, you may be missing your full potential.

For example, as I've started my new project, I have wanted to make things a little bit tidier.

One of the ways to do that is to be more proactive with my approach to logging.

Yes, default logging could use a little sharpening.

There's a good article by Guilherme Latrova that provides really good guidance on why/how you may want to go about logging in Python. A bit from the article:

Most people don't know what to log, so they decide to log anything thinking it might be better than nothing, and end up creating just noise. Noise is a piece of information that doesn't help you or your team understand what's going on or resolving a problem.

Creating noise is an example of working with a dull blade. It will only make your life harder.

However, good logging can give you valuable context, providing you with information you need right away in order to monitor and/or course-correct when things go wrong.

Yes, this speeds up your development.

Richify Your Logger

I may have edited this heading after seeing Will's tweet.

Maybe you've heard of Rich? You know, it makes your print statements look very pretty!

That alone as a tool could really help your development.

But what's more, Rich comes with it's own handler that you can use with your logger.

For my new project, I reference a post by Hayden Kotelman titled FastAPI and Rich Tracebacks in Development.

I use a similar approach, ensuring that my tracebacks/logging are readable and pleasant—but most of all, useful.

Before I begin, take a look at what a typical traceback looks like in my project without Rich:

Nothing out of the ordinary.

Alright, so let's begin.

First, here's the relevant packages:

import logging
import sys
from functools import lru_cache
from pathlib import Path

from myapp.config import settings  # my own config
from pydantic import BaseModel

My configuration file has a few variables that I keep handy, but I go ahead and define my logger format here.

LOGGER_FILE = Path(settings.LOGGER_FILE)  # where log is stored
DATE_FORMAT = "%d %b %Y | %H:%M:%S"
LOGGER_FORMAT = "%(asctime)s | %(message)s"

I then use a pydantic model to hold my logger configuration info.

class LoggerConfig(BaseModel):
    handlers: list
    format: str
    date_format: str | None = None
    logger_file: Path | None = None
    level: int = logging.INFO

My next piece of code is nearly identical to Kotelman's.

@lru_cache
def get_logger_config():
    """Installs RichHandler (Rich library) if not in production
    environment, or use the production log configuration.
    """

    if not settings.ENV_STATE == "prd":
        from rich.logging import RichHandler

        output_file_handler = logging.FileHandler(LOGGER_FILE)
        handler_format = logging.Formatter(
            LOGGER_FORMAT, datefmt=DATE_FORMAT)
        output_file_handler.setFormatter(handler_format)

        return LoggerConfig(
            handlers=[
                RichHandler(
                    rich_tracebacks=True,
                    tracebacks_show_locals=True,
                    show_time=False
                ),
                output_file_handler
            ],
            format=None,
            date_format=DATE_FORMAT,
            logger_file=LOGGER_FILE,
        )

    output_file_handler = logging.FileHandler(LOGGER_FILE)
    handler_format = logging.Formatter(
        LOGGER_FORMAT, datefmt=DATE_FORMAT)
    output_file_handler.setFormatter(handler_format)

    # Stdout
    stdout_handler = logging.StreamHandler(sys.stdout)
    stdout_handler.setFormatter(handler_format)

    return LoggerConfig(
        handlers=[output_file_handler, stdout_handler],
        format="%(levelname)s: %(asctime)s \t%(message)s",
        date_format="%d-%b-%y %H:%M:%S",
        logger_file=LOGGER_FILE,
    )

Wow, that's a lot of sharpening!

The articles I linked might give you more context as to what's going on here, but here's the general gist of it.

If you are not in production, the function get_logger_config imports the RichHandler and sets it in motion.

You'll note that RichHandler has a few options, but you can get a sense of how customizable it is by reviewing the documentation.

Ultimately, you set the handler to show up on your terminal through stdout_handler, and the setFormatter method allows you to pull in your new handler format.

Overriding

Logging in Python can be a bit confusing for newbies like myself, especially coming fresh into it. Each library could have its own logging configuration/handlers, and the layers could run deep.

Logging in FastAPI can be tricky because Uvicorn (the server that FastAPI runs on), has its own logging mechanism.

Ultimately, what I wanted to do was remove other logger handlers (specifically, Uvicorn), and use RichHandler instead.

def setup_rich_logger():
    """Cycles through uvicorn root loggers to
    remove handler, then runs `get_logger_config()`
    to populate the `LoggerConfig` class with Rich
    logger parameters.
    """

    # Remove all handlers from root logger
    # and proprogate to root logger.
    for name in logging.root.manager.loggerDict.keys():
        logging.getLogger(name).handlers = []
        logging.getLogger(name).propagate = True

    logger_config = get_logger_config()  # get Rich logging config

    logging.basicConfig(
        level=logger_config.level,
        format=logger_config.format,
        datefmt=logger_config.date_format,
        handlers=logger_config.handlers,
    )

Reference: Unify Python logging for a Gunicorn/Uvicorn/FastAPI application

What It Looks Like

I originally published this piece without any images to show the end result.

My bad. Still getting used to this blogging thing.

To invoke the logger in FastAPI, I call the function after declaring my application. Something like:

from fastapi import FastAPI
from app.logger import setup_rich_logger

def get_app() -> FastAPI:

    app = FastAPI()
    setup_rich_logger()

    return app

app = get_app()

For fun, I've inserted the following lines of code in the module where I instantiate my database connection:

Note that for my "debug" message to show, I have to change the level in my LoggerConfig class.

level: int = logging.DEBUG

Once I start up my FastAPI application. I am greeted with the following:

And when things go wrong:

...and so on...

And then one final look when things are in working order. I set the level back to INFO and removed the logging lines from above.

I'm quickly able to see when my database is online, which Beanie documents are being picked up by my model finder, what are my recent articles that I've published, and whenever someone's trying to login.

It still could use a little more sharpening, but this already makes my life so much easier.

In Closing

This is hardly a peek at the toolbox available to you when coding in Python.

But I did want to point out how spending a little time up front setting up your logger could potentially save you tons of time down the road.

Don't stop there, though.

Let me know what other tools you keep sharpened to aid in your coding adventures!