Decoding the Digital Trail: A Deep Dive into Software Logging Part 1

Debugging a backend error in production is incredibly challenging especially if you rely solely on the random luck of console output. Without a defined structure for this output or the assistance of error monitoring software, you are like a deep-sea diver exploring uncharted waters without a map or a compass, hoping to find hidden treasure amidst the vast and murky depths. But don’t sweat! Luckily, for us developers, there is an underrated process called logging that helps guide us through these tough times of debugging and offers insight into why and how an error happened.

If you’re brand new to logging, I trust this blog will serve you well. As this is part one of a two-part series, we will first start off with learning the fundamentals of logging and building a foundation. Then in part two, we will apply our new found knowledge to solve real world problems by leveraging Amazon’s CloudWatch Logs service.

Without further ado, let’s explore the following topics:

• Advantages and disadvantages to software logging
• Log levels
• How to write logs
• Considerations

Advantages and Disadvantages of Logging

Put simply, logging refers to the practice of recording information or events that occur during the execution of a program. I have spoken about it in the context of debugging production errors, however, you’ll be glad to know that it offers much more:

Pros

• Helps developers catch bugs or mistakes in the code.
• Keeps track of how well a program is doing (monitoring and analysis).
• Enables you to keep an eye on any suspicious activity.
• Logging enables the initiation of alarms to alert developers when the system is behaving outside the bounds of the norm.
• Minimize time to resolution (for an error).

Cons

• Logging sensitive information can pose a security risk.
• Extensive or inefficient logging can have a noticeable impact on performance.
• Logging user activities without proper consent or logging excessive details about user behaviour could raise privacy concerns.

Investing significant time in creating high-quality logs can be very valuable, which one might argue is essential for all software systems. However, let’s pause and consider the flip side where logging is neglected. To illustrate this, let’s examine the following table where I share the impacts of software gone bad in multiple industries:

Table outlining the consequences of neglecting to log in various applications of different industries.

Looking at the consequence column, we can begin to recognize that any downtime in such applications can have some serious adverse effects. Now, this might not be the scale at which your current application operates, but as your user base grows and the system increases in complexity, you will want to invest in a solution that will provide some “damage control” and logging does just that.

What are Log Levels?

In the context of Javascript, you are probably familiar with our good friend console.log and have used it to output information to assist you with debugging. While the log method is often considered the catch all method for general logging, it doesn’t necessarily mean it’s always the right method. Let’s consider the other log level methods that are available on the console object and understand its application.

Table outlining additional log level methods on the console object, a brief description and example.

Using different log levels for different types of log messages can help you categorize and prioritize the information, making it easier to identify and address issues in your code. For demonstrative purposes, let’s explore the output of each log level inside the AWS CloudWatch Logs interface:

console.log('Customer is atempting to purchase a product')
console.info('Customer is attempting to purchase a product')
console.warn('There are no products available')
console.error('Unable to purchase product')

Log events captured in AWS CloudWatch Logs.

As you can see, CloudWatch Logs recognizes these log levels and labels each log event accordingly. Conveniently, there is also a search bar located at the top of the page to allow filtering based on log levels.

Log events filtered by the error log level.

So How Do We Actually Write Logs?

Now that we understand the semantics behind log levels, the next step to learn is how do we write logs? And what should we log? Let’s take a look at the following table to help us understand what options we have:

Table outlining log options.

With this table in mind, let’s consider a hypothetical situation where you access an online shopping platform.

E-commerce page with a list of products.

As a customer, you enter the website with products for sale loaded onto your screen. You proceed to add a product into your cart and navigate into the cart review page to make the purchase. Upon clicking the purchase button, error text appears that reads “Something’s Gone Wrong!”.

How might you go about generating logs to reflect the actions you have recently performed? If we consider the request/response approach (outlined in the table above) we can make an attempt to visualize the output of the logs. For this output, we will log the status code, method, route followed by the username and description of event.

Log events captured in AWS CloudWatch Logs.

Evidently, each log tells us just enough information to let us know our possible interactions on the website. Focusing on the last four events, we can see the success and failures of certain backend endpoints (through status code) and also get a small summary provided for each event. Since these logs are a result of responses coming back from an API endpoint, you can start to imagine where in the code the logs may be positioned:

app.post('/purchase', async () => {
  try {
    await purchaseProduct()
  } catch () {
    console.error('Event: 500 POST /purchase - User JohnDoe received an error during the purchase process.'
  }
})

Now, what if we wanted to provide more details about the error and do not wish to output just text? We can simply replace the text and consume a JSON object instead (the consumption of a JSON object is commonly referred to as structured logging, you can learn more about it here). As you can imagine, a structured log can help make it easier to debug, parse and filter logs based on specific properties. It offers several advantages over plain-text logs, including but not limited to enhanced search-ability, consistency, and contextual information. If we consider contextual information, structured logs often include additional information such as request IDs, user IDs / usernames or error codes making it easier to understand the context of each log entry.

For simplicity, I have hard coded most fields in the example below, however, in a production environment you will want these fields to be dynamic to allow flexibility. Although there are best practices for including certain properties in error logs, these properties are not set in stone. Ultimately, it is up to the developer to determine the properties and the appropriate amount of data needed to troubleshoot a problem in production.

app.post('/purchase', async (req) => {
  try {
    await purchaseProduct(req.body.productName)
  } catch (e) {
   const logData = JSON.stringify({
     method: 'POST',
     route: '/purchase',
     status: 500,
     message: e.message,
     data: {
       username: 'JohnDoe',
       productName: 'christmas-sweater'
     }
   })
   
   console.error(logData)
  }
})

CloudWatch output:

Log event captured in AWS CloudWatch Logs.

What we see here is a structured log that provides a consistent format that includes important contextual information. We can quickly analyze that the user JohnDoe has made an attempt to purchase a product “christmas-sweater” but the purchase fails with an error message that reads that there is “no more inventory”. On the frontend however, this message has been translated to “Something’s Gone Wrong!”. Due to this discrepancy and the log containing the actual error, it is crucial for the backend to relay this error message to the frontend for effective customer communication.

Considerations

When creating your logs on the backend here are some points to consider:

• How can I capture relevant information for debugging, monitoring or auditing purposes?
• What is the absolute minimum amount of information I can include to avoid excessive and cluttered logs?
• How might I make it easier for myself to reproduce the error on the front end?
• How might I categorize my message with a log level?
• How might I use this log to trigger custom alerts to notify developers of abnormalities?
• How can I ensure I am not logging sensitive information?

By carefully considering the points above when creating backend logs, you can ensure that your logs are both effective and efficient. Capturing relevant information for debugging, monitoring, and auditing is crucial, but it is equally important to avoid excessive logging that could lead to clutter and hinder our ability to quickly identify issues.

Another consideration you can make is determining where the log ends up being stored or outputted. Up to this point, most of the log output on this blog has shown up on Amazon CloudWatch Logs. It is important to note that this is up to the developer’s discretion based on their specific requirements and preferences. Logs can simply appear in the console or terminal window, written to one or more files, stored in a database, sent to a remote server, sent to third-party logging services or sent to cloud-based logging services like we have done here (CloudWatch Logs).

What about Logging Libraries?

Granted logging libraries do offer several advantages and do work well with services like CloudWatch Logs, for the purposes of this blog, I have written out the logs manually. However, if you are still interested here are some popular Node.js logging libraries: Winston, Pino, Bunyan.

Conclusion

Remember, effective logging is not just about recording errors — it’s about capturing the heartbeat of your application. By leveraging the insights from your logs, you can proactively address issues, optimize performance, and drive continuous improvement. Keep experimenting, refining and adapting your logging strategy as it will lead to a more resilient and successful application. And last but not least, ensure to advocate for logging within your software team to promote better debugging, monitoring and overall system reliability.

This marks the end of part one. If you’ve enjoyed reading this blog, keep an eye out for part two, where we’ll build on these foundational insights to tackle real-world production challenges using AWS CloudWatch.

Happy logging!

Four Nine is a full-service Digital Agency located in Vancouver, BC. Learn more about us by visiting our website or contact us at info@fournine.digital.