Mirosław FarajewiczThis article is an extension of what I wrote in 5 tips for dev rookies. The idea behind the original article was to overly describe important concepts that you can improve in your work.
I wanted to deliberate a bit more about logging, so I decided to create a separate article.
Should I care about logs?
With broken logs you would be walking alone in the dark when searching for a bug. What’s more, with logging mechanism not implemented at all you won’t even know that there is a bug.
With logs, you can simply start the day with a mug of coffee and check what errors happened during the last few hours in the night. If these are known issues then you won’t appreciate it so much**. However, if something new and unexpected occurs you may be sure that a well-formed stack trace with a meaningful error message will make you think “I got you, you little fu**&”.
With logs, you can easily find what happened on your customer’s account without a bigger interviewing session.
How you can tell that there is something wrong with logging in your application? Well, it can be broken in many different ways.
I won’t dig this topic so deep to debate which logging library or log processing pipeline is the best (well processing pipelines are not very junior dev topic). I would like to discuss a few more basic and overall concepts.
** Which means that they either should be fixed or you log things that perhaps should be omitted?
Understand your framework
Most of the modern frameworks (at least the backend ones) have built-in functionality of logging. While logging information and warning messages are self-explanatory, dealing with errors can have different scenarios and many developers just omit this knowledge and follow approach “ok I will use any method for logging and it will be fine”. Well, it won’t be fine. What’s worse by using logging methods in the wrong way you are turning logs into garbage.
Some libraries log errors using a method like error(message) and it produces entry with your log with that message, timestamp and log level.
Some have separate method for logging exception object such as logException(Exception e)
which usually takes an exception message and combines it with a stack trace and then puts that as an error entry to your log.
It’s also popular to have one method such as error, but with the possibility to add context or exception object - then the method extracts stack trace and builds proper error message on top of it.
Spend 2 minutes on reading documentation in the #logging section of your framework or logging library.
Code-level mistakes
There are many basic code-level mistakes when using the logging mechanism in our app. Most common are those when dealing with exceptions.
For the sake of example let’s assume our app is a web scraper extracting data from some job board. We want to get details of each job extracted from the main page of our target job portal. We are requesting pages using abstract HttpClient.
Before we start let’s imagine a little mind experiment. For each situation - imagine what your co-worker would see in the log on the next day morning when he starts his day in the office, assuming that some error occurred in the piece of code written by you.
Not logging exceptions at all. I’ve seen this way too many times in codebases.
try { httpClient.get(url) } catch (e) { }
Assume that your app scraping was supposed to scrap 2 thousand URLs and failed on yetanotherjobboard.io/junior-web-dev.
Monday, morning. Your coworker is enjoying his first coffee - while checking logs to learn what happened during the night. What would he see in logs?
Nothing, blank.
You don’t even know that during the night some of the URLs were not parsed.
Fixing logging, in this case, is obvious. Assuming that your logException method deals properly with logging exception and does not commit any of the next mistakes it would like like this
try { httpClient.get(url) } catch (e) { logger.logException(e); }
This example assumes that logException method saves every important piece of information. Otherwise, we need to separately save exception and information about it. See the next examples
- Logging without adding details about what went wrong.
Try {
httpClient.get(url)
} catch (e) {
logger.logException(e);
logger.logError(‘Was not able to parse URL’);
}
That’s better than problem 1) because at least we know something unexpected happened but still missing a crucial part of the problem. It’s also an example of what I mentioned in “Understand your framework” section. We have two separate methods - one for logging exception itself, and second if we want to save entry with our own error message.
What would your team-mate see at the morning after parser failed to process one of the URLs?
Stacktrace with line of code of you HttpClient failing.
Plus next log would be info “Was not able to parse URL”.
Cool but if you are to fix your parser then you need to know what URL was not parsed. You would like to enter this URL in the browser or curl it in the command-line to manually check why it’s failing.
Fixing this case would make this code like this:
Try {
httpClient.get(url)
} catch (e) {
logger.logException(e);
logger.logError(‘Was not able to parse url ’ + url);
}
- Logging exceptions only as error messages. No stack trace logged, which is the same if not more important than a meaningful error message.
Try {
httpClient.get(url)
} catch (e) {
logger.logError(‘Was not able to parse url ’ + url);
}
This example mostly depends on the implementation of logError message but I assume it only logs passed message + marks an entry as ERROR.
In a situation like this you would like to know:
What URL failed - checked
Why it failed - not checked. It may be because the parsed website had a temporary glitch, and we got some 500 response. Our HTTP client could have timeout-ed because of internet problems on our side. Or our parser could have been banned?
Fixing depends on the rest of the code and classes you have, but probably it will be something like this. Stack trace (logging exception itself) will be an answer to our questions
Try {
httpClient.get(url)
} catch (e) {
logger.logError(‘Was not able to parse url ’ + url);
logger.logException(e);
}
Being command-line log ninja
Also at the end, I would like to mention one thing which is a way of dealing with logs. Learn to view them in a handy way. Especially if you are comfy Windows user and have to read logs directly on the Linux machine.
If you are this type of user that first looks for GUI equivalent of every app, and you have to check some logs directly in the command line or DB console you may feel a bit lost. Test those commands for reading logs in Linux terminal:
tail -f -n 200 /var/logs/nginx.log
And make them a habit.
Also adding parameter -F for continuously displaying new lines is helpful
If you have to deal with logs in MySQL console you may find useful SQL switch \G - it makes better display of multi-row columns making log from this format:
Learn how to quickly transform machine-friendly timestamps into readable formats eg. SQL's from_unixtime(col) is a good start. Also, substr function allows to quickly retrieve part of long data for analysis.
Combination of from_unixtime and substr is a simple yet powerful way to find your way through logs jungle.
select substr(LOG_COL, 1, 40), from_unixtime(TIME_COL) as date from LOGTABLE order by id desc limit 10;
Show last 10 logs with readable human time and extracted beginning of log message
Also if you are interested in different time frame you can use DATE_SUB and DATE_ADD methods
Such as
select substr(LOG_COL, 1, 40), from_unixtime(TIME_COL) as date from LOGTABLE where from_unixtime(TIME_COL) > '2019-08-24' AND from_unixtime(TIME_COL) < '2019-08-26';
Those commands won’t make you ninja yet, but they are a good foundation.
What’s next
This is just the beginning of a broad topic of logging. When you get familiar with all the concepts presented in this article you can dig deeper.
Subject such as configuring and using a logging pipeline is what you should learn further. Of course, it’s out of the scope of tutorial for beginners like this. However, using tools such as Logstash and Kibana can boost the quality of your app as it helps you better monitor and alert on anything unexpected happening in the app.
If you like this article get familiar with 5 tips for dev rookies - I will soon write another elaboration on the “Feedback loop” subject.
Also, follow me on twitter if you want to stay up-to-date with all my articles.
