https://tuhrig.de/my-logging-best-practices/ Thomas Uhrig Thomas Published January 16, 2020 Skip to content * About * Privacy Policy * Impressum [abstract-1846059_1280-700x466] Thomas in Coding | January 16, 2020 My Logging Best Practices If you are a backend developer like me, logging is the window to your application. Unlike in the frontend, there's not much to see except from some logging messages. Here are some of my personal guidelines I use when I write logs. Log after, not before Back in the days, a logbook was written on every ship. It was like a diary which recorded important events throughout the day. And just like a traditional logbook, we should log things that had happened instead of things we are going to do. Let's make an example: 1 // don't do that 2 log.info("Making request to REST API") 3 restClient.makeRequest() 4 5 // do that 6 restClient.makeRequest() 7 log.info("Made request to REST API") The first log statement doesn't tell much. When reading it, you will not know if the REST call was successful or not. To do so you must look for the absence of an exception. And if you read this log but miss the subsequent exception you will be confused for the rest of the day (trust me). The second log is much better. It clearly states that the operation right before was successful. If the REST call would have failed, you would not see this log - there would be an exception instead. I apply this rule to all INFO logs. However I make exceptions for DEBUG. Separate parameters and messages A typical log message contains two types of data. One type is a handwritten message which states was is going on. The second type is a list of (technical) parameters involved in the operation. You should try to separate both parts. 1 // don't do that 2 restClient.makeRequest() 3 log.info("Made request to {} on REST API.", url) 4 5 // do that 6 restClient.makeRequest() 7 log.info("Made request to REST API. [url={}]", url) The first log message has some flaws. It's difficult to parse for example for Grok patterns. So it becomes harder to automatically extract IDs or parameters in our logging tool. It's also difficult to read. Imagine having a very long URL possibly with a list of parameters at their end. Half of the log message might be out of your screen. And of course, the message is more difficult to extend. If you want to add another parameter (such as the HTTP method used) you must rewrite you whole sentence. The seconds version has none of these flaws. It's easy to parse because the parameter list has a clear syntax. It's easy to read, as you can see the sentence right up-front. And it's easy to extend as you can just add another parameter to the list. Distinguish between WARNING and ERROR Obviously, log levels are there for a reason and you should use them appropriately. And there are some key differences between a WARNING and an ERROR. If you did some operations which actually worked, but there have been some issues - that's a WARNING. But if you did some operation and it simply didn't work - that's an ERROR. Let's look at an example again: try { 1 restClient.makeRequest() 2 log.info("Made request to REST API. [url={}]", url) 3 } catch(e: UnauthorizedException) { 4 log.warn("Request to REST API was rejected because user is 5 unauthorized. [url={}, result={}]", url, result) 6 } catch(e: Exception) { 7 log.error("Request to REST API failed. [url={}, exception={}]", 8 url, exception) } The REST call might have one of three outcomes: * It can work like a charm. That's an INFO (after the call). * It can fail with an unexpected exception. That's an ERROR ( instead of the INFO log). * It can result in some expected exception. That's a WARNING. So in case of a WARNING, you did something, but you didn't do it perfectly. In case of an ERROR you didn't do it. Also note that a WARNING (and also an ERROR of course) is a call to action. If nobody needs to react and to do something, then you don't need to log a WARNING. INFO is for business, DEBUG for technology The INFO log should look like a book. It should tell you what had happened, not necessarily how. This means that INFO is better suited for business-like log messages compared to technical stuff. Technical related messages should (usually) be DEBUG. INFO | User registered for newsletter. [user="Thomas", email= 1 "thomas@tuhrig.de"] 2 INFO | Newsletter send to user. [user="Thomas"] 3 INFO | User unsubscribed from newsletter. [user="Thomas", email= "thomas@tuhrig.de"] This type of log tells you a story from the point of view of our business. Now what are technical logs? DEBUG | Saved user to newsletter list. [user="Thomas", email= "thomas@tuhrig.de"] 1 DEBUG | Send welcome mail. [user="Thomas", email="thomas@tuhrig.de" 2 ] 3 INFO | User registered for newsletter. [user="Thomas", email= 4 "thomas@tuhrig.de"] 5 DEBUG | Started cron job to send newsletter of the day. [ 6 subscribers=24332] INFO | Newsletter send to user. [user="Thomas"] INFO | User unsubscribed from newsletter. [user="Thomas", email= "thomas@tuhrig.de"] Every (business) use-case results in a single line of INFO log. Additionally, there are DEBUG logs which give a more detailed insight in how the process works. Much more Of course, there's much more to do for good logs. You also need to consider things like tracing, log aggregation and metrics. But when it comes down to the pure writing, I really recommend those little rules. Best regards, Thomas Related Posts * Basic Auth log-out with JavaScript * Simple permission handling in AngularJS * Expression based security with Spring Security * DDD with Kotlin Thomas Published January 16, 2020 Write a Comment Cancel Reply Write a Comment Comment [ ] [ ] [ ] [ ] [ ] [ ] Name[ ] Email[ ] Website[ ] [Submit Comment] [ ] [ ] [ ] [ ] [ ] [ ] [ ] D[ ] 1. Aniket Karmarkar October 5, 2021 everything is subjective. especially laws. Reply to Aniket 2. Gilbert Fernandes October 5, 2021 about "Separate" stuff. No. Use key=value For example if you do a REST call, output ONE and only ONE line for the result. Where everything is key=value method=nameOfRestMethod , called=URL , httpStatus=200 , elapsedTime=xx , error=none , param1=x , param2=y name of method will be used by developer if anything has a bug or something. httpStatus can be parsed to find all the 200 or non-200 httpStatus results, etc, etc. this lets you parse EACH line to grab important data and feed it to an ElasticSearch of whatever. find all lines where key has value X or different than value X. logs should be made so they are parsable through keys because this is VITAL not only for busines, but more important of all : S E C U R I T Y. Reply to Gilbert * Related Content by Tag * Architecture * Logging Search [ ] [Search] Like my blog? Buy me a coffee Tags Academic ActiveMQ AI AngularJS Architecture Blogging Book CI/CD Cloud Data-Mining DB Design Pattern Docker Download Eclipse ERASMUS Google HdM HTML Informatica Java Java 8 JavaScript JMS JUnit Kotlin Linkoping Linux LiU OSGi Personal Picture Programming Python Security Slides Spring Sweden TechTrends Testing Travel UI Web Windows Wordpress Archives * July 2021 * June 2021 * January 2021 * January 2020 * July 2019 * February 2019 * December 2018 * October 2018 * August 2018 * June 2018 * May 2018 * March 2018 * February 2018 * January 2018 * December 2017 * November 2017 * June 2017 * May 2017 * March 2017 * February 2017 * January 2017 * December 2016 * November 2016 * October 2016 * May 2016 * February 2016 * January 2016 * December 2015 * November 2015 * August 2015 * June 2015 * May 2015 * March 2015 * February 2015 * January 2015 * July 2014 * June 2014 * May 2014 * April 2014 * March 2014 * February 2014 * January 2014 * November 2013 * October 2013 * August 2013 * July 2013 * June 2013 * May 2013 * March 2013 * February 2013 * January 2013 * December 2012 * November 2012 * October 2012 * August 2012 * July 2012 * June 2012 * May 2012 * April 2012 * February 2012 * October 2011 * July 2011 * March 2011 * September 2010 * August 2010 * July 2010 * June 2010 * May 2010 Independent Publisher empowered by WordPress I use cookies to ensure that I give you the best experience on my blog. If you continue to use this site I will assume that you are happy with it.Ok