This is your friendly reminder to be thoughtful about logging when writing software. This can sometimes be similar to naming, which many of us joke is the hardest part about writing software.

It's a bit of a goldilocks conundrum, too little and you don't have the necessary information to troubleshoot a piece of code, too much and you need to sift through information that may not be relevant, especially if you're not the one that wrote it in the first place.

However you do logging^[1]Using standard output is more acceptable now with how logging is done with cloud services, but you still might want to consider a logging library., this is about what you log and when. There are no hard rules, but it's something you should think about as the piece of code you're writing nears completion. Go back and clean it up! Remove the things like the indexes you logged in a loop, make sure logging is in place at important decision/conditional points. What is going to help you a year from now when you get a request to investigate an error in this part of the system?

Did a database write fail because of a key constraint? What was that key? Maybe it was expected to be unique but was not, how was the key created or derived?

This type of logging will pay dividends over time, and your future self will thank you. The following are some examples of things I've seen in the past that have lead to confusion or prevented me from being able to troubleshoot without making modifications. Most issues are obvious after the fact, and you might ask why someone would do that in the first place. Their attention was probably drawn to other areas like functional specification, logging just happened as it was needed.

---

Preemptive Success Logging

Sometimes I've seen a log message written about the outcome of something, before that thing has been done.

def update_active(url, active_flag):
    print(f"Active flag updated to {active_flag}")

    response = requests.post(
        url=url,
        data={
            "active": active_flag,
        }
    )
                

Yes, I really have seen that before.

This is obviously problematic, if the HTTP call fails then our log of what happened does not match reality. Depending on what you're interfacing with and what libraries you're using then the call may throw an exception, so hopefully that gets logged somewhere and not suppressed, but there's no guarantee. In the case of the python requests library for example, if that call returns a 400 level status then it will return that information to you in the response as opposed to raising an exception.

Which leads to another common thing I've seen:

def update_active(url, active_flag):
    response = requests.post(
        url=url,
        data={
            "active": active_flag,
        }
    )
    
    print(f"Active flag updated to {active_flag}")
                

Here the log entry is moved to after the HTTP call. That's a bit better, but again, we don't know if the call was successful. The response minimally needs to be checked for the proper status code before declaring success.

Make sure you validate the state of something before you write a log entry about it.

---

Partial Logging

Sometimes you need to take pieces of input to create something. Say for example the creation of a URL:

def get_job_info(domain, job_id):
    print(f"Domain: {domain}")
    print(f"Job Id: {job_id}")

    url = f"http://{domain}/jobs/{job_id}"

    response = requests.get(url)
                

Notice that domain and job_id are logged^[2]Yes, I'm using print() for these examples and not formal logging., but not url. The code is making the assumption that the URL is accessible over HTTP, but maybe^[3]Hopefully that was in the lower level environment and production is different.

Looking at the logs you would see the parts of the final URL, which you may cross reference and find to be good, but without looking at the code you wouldn't understand that the protocol is wrong.

Make sure to log the final value that will be used for something, not just the composite pieces.

---

Logging in Loops

Perhaps you're doing validation on items in a list. When you encounter an item that doesn't validate correctly you raise an exception.

def validate_configs(config_list):
    for config in config_list:
        if "id" not in config or not _valid_id(config["id"]):
            raise Exception("Invalid config found in config list")
                

Which item was the offending one? It sure would be nice to have some more information to shortcut digging through all of those configuration items.

If the items have ids associated with them then you could log the id, you could also log the whole item to see what other information was in it that made it unique. If the collection is ordered you could include the index of the item. Logging every index is not helpful, but logging the index when a specific issue is found can be.

When dealing with collections, make sure to capture information about the offending item in your logs.

---

Logging isn't a complex part of writing software, but it's extremely important. Important enough that you should actually think about what you're logging. When doing development there are times that you reach for a debugger and times when it's faster to add some throw away log entries, but remember to remove them when things are tested and done. Once everything is done, execute your code and examine the log output. Does it contain everything you'd need to know if something went wrong? Does it contain too much?^[4]This includes sensitive information!

Take a second pass at your logging just like you would cleaning up/refactoring the rest of your code when it's finished.^[5]I really tried to find a play on "Be kind, rewind" for logging, but alas I came up empty.