Logging Practices: Guidelines for Developers

Logging is a fundamental component of any software product which plays a crucial role in understanding how the software is used and preserving knowledge about its historical and current states. Without effective logging, a product becomes a black box, hindering developers’ ability to monitor its real-time operations and investigate issues.

The consequences of neglecting good logging practices are significant, as it makes debugging a challenging and time-consuming process. This, in turn, leads to delays in subsequent release cycles, whether they are required for resolving bugs, accommodating feature requests, or implementing change requests.

Moreover, the absence of robust logging mechanisms deprives the business of essential tools for observability and monitoring, which are critical for maintaining the reliability and performance of any software product.

In this guide, we’ll explore some of the best practices for effective logging, tailored for developers of all levels, whether you’re a fresh face or a seasoned pro.

Meaningful log statements 📑

To get the maximum value out of the application logs they need to be appropriate.

Now, consider some of the logs written below.

log.error("invalid input received") 
log.debug("File not found: %s", fileName)

Some of the problems with the above logs are

• lacks insight
• incorrect log level

The refined versions may look like

log.error("Invalid input received for parameter 'username' ")
log.error("File not found: %s", fileName)

Moreover, the programming language or frameworks provide distinct log levels to refine the log statements.

Usually, they are one of these(feel free to skip if you are aware)

TRACE, DEBUG, INFO, WARN, ERROR, FATAL, OFF

1. The TRACE log level is used for extremely detailed logging. It is typically used for low-level debugging rather than for general application logging. It's important to use it judiciously, as excessive TRACE logging can impact application performance and consume significant resources.

log.trace(“Tracking package in the warehouse: %s”, packageID)
log.trace(“Scanning package contents for security checks: %s”, packageID)

2. As the name implies, DEBUG is to denote the debug information which can later be used to analyse certain scenarios.

log.debug(“Calculating estimated delivery time for shipment: %s”, shipmentDetails)
log.debug(“Verifying product availability before processing order: %s”, productDetails)

3. The INFO log level is used to denote the current state of the application. INFO level logs are especially useful for monitoring the application and keeping track of its behaviour.

log.info(“Shipment successfully loaded onto delivery truck. Tracking ID: %s”, trackingID)
log.info(“Processing payment for delivered shipment. Invoice ID: %s”, invoiceID)

4. The ERROR log-level denotes the erroneous state within the application. When an error is logged, the application can continue to function, but the error needs to be addressed.

log.error("Invalid shipping address provided for order: %s", orderDetails)
log.error("Failed to update inventory after order fulfillment. Product ID: %s", productID)

5. The FATAL log level is used to indicate that the application has encountered a non-recoverable state and needs immediate attention. At this log level, the application may not work normally and could crash or stop working altogether.

log.fatal("Critical error: Unable to connect to the central shipping database. Application shutting down.")
log.fatal("Security breach detected. Immediate suspension of all shipping activities.")

6. The OFF log-level turns off the logging and you never get to see the log

Another important aspect of high traffic or big applications is the size of the logs. Too little or too many of the logs are bad. It’s important to find the right balance.

As a developer, it’s a skill to write the optimum log statements 😈

Logging vs Debugging? 🤔 🪵

Do you remember these often-used log statements?

log.trace("Entering function with params: %s", params)
log.debug("Processing data: %s", data)
log.info("Processing started...")
log.error("Caught exception: %s", exceptionDetails)

They are not useful other than to check if the control reaches a code flow or if an expected processing has begun.

All such statements add Noise to the overall logs.

While logging, it is important to make a distinction between SIGNAL and NOISE!

Noise usually consists of tons of logs which do not help us decode the situation. Rather it may pollute the logs and ultimately make it difficult to find the relevant ones.

The signal helps a developer deduce the situation by the first look of it.
Below are some refined logs that are a Signal to the system.

log.trace("Entering critical section: Processing payment for order %s", orderId) 
log.debug("User authentication successful: %s logged in", user)
log.warn("Low stock alert: Product %s stock level is below the threshold", stockId)
log.error("Payment gateway connection failed: Unable to process order %s ", failedOrderId)
log.fatal("Critical security breach detected: Unauthorised access attempted") 

Consider the below example of logs where the Redis connection failed multiple times but without a clear reason.
Also, it has cluttered the logs making it difficult to focus on other important logs.

Control the logs at run-time 🤔 🪵

It is very clear from the last section that logs are helpful only when written with due diligence. Also, it is a fact that one can not control the number of logs that are produced. Hence it may create a problem where a developer may get overwhelmed with valid but unnecessary logs. In such a situation, one wants to restrict certain log levels to control the logs and focus only on required logs to get deep insights about a bug or a behaviour.

As a developer, we should have a mechanism in place to dynamically control the log levels.

For example in Spring Boot, you can dynamically change the log level at runtime by sending an HTTP request to an endpoint /actuator/loggers/{loggerName} with a JSON payload.

Let’s say, to change the log level of the org.springframework.web package to INFO, you can send the following request

POST /actuator/loggers/org.springframework.web HTTP/1.1
Content-Type: application/json
{
  "configuredLevel": "INFO"
}

This will change the log level to INFO and hence all the logs with the levels above will not be shown.

Logging framework 🪟

Products are being developed by a team. Different developers within a team tend to choose different patterns for logging. Hence this may induce certain problems like those below

• inconsistent format to write logs
• no central place to control the logging configuration
• no single security policy to safeguard log files or define file rotation policy etc

As a developer, we have to choose the relevant logging library so that

1. it brings uniformity in the logging practices at a product level
2. to have a single place to configure logging settings
3. to make sure that the logs are safe and avoid any security issues
4. and to not reinvent the wheel !!

Consider the simplest example of log4j2 config file

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %logger{36} - %msg%n"/>
        </Console>
        
        <File name="File" fileName="myapp.log">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %logger{36} - %msg%n"/>
        </File>
    </Appenders>
    
    <Loggers>
        <Root level="INFO">
            <AppenderRef ref="Console"/>
            <AppenderRef ref="File"/>
        </Root>
    </Loggers>
</Configuration>

The above config file sets some of the rules at the application level. Let’s decode them

1. Logs will be printed to standard Console and File (saved as myapp.log)
2. Since the root level is INFO hence
   - all the levels below will be part of the logs — INFO, WARN, ERROR, FATAL
   - all the levels above will not be part of the logs — DEBUG, TRACE
3. The log will be printed in a certain pattern. Below is one such example.

15:45:22.345 INFO  com.myapp.UserController - User 'john.doe' successfully logged in.
15:46:01.123 WARN  com.myapp.OrderService - Order #12345 is pending for delivery.
15:47:15.789 ERROR com.myapp.DatabaseConnection - Failed to establish a database connection.

This helps the engineers to work in tandem and be consistent about the logs that are being produced by the application.

The table lists some of the commonly used frameworks and respective libraries

|   Framework   |    Logging library     |
|---------------|------------------------|
| Spring Boot   | Logback, Log4j2, SLF4J |
| Kotlin        | Logback, SLF4J         |
| Ruby on Rails | Rails logger, Lograge  |

Derive values out of the logs 📊

Product teams create application metrics out of the logs. Later such metrics could prove useful to derive insights and make data-driven decisions.

Consider the log statements as part of the cron job

log.info("Processed orders count : 100")

The above log can be used to create a dashboard that displays “Completed orders/hour”.

As a developer, it is important to ask if the log statement helps derive certain metrics.

Certainly, this is not a simple task and more often requires a holistic thought process. But once done, it can be of great help for the wider stack holders including the C Suite.

One such example of a tool that can be used to aggregate & generate dashboards from logs is DataDog. It allows you to create custom metrics and alerts from log data and visualise them in a variety of ways including charts and graphs.

Now below are some use cases depicting the value the aggregated logs are producing.

Scenario 1: Showcase errors from the past hour originating from various sources such as ad-server, orders-database, orders-app, and payments-app.

Scenario 2: Retrieve the distinct Cart IDs for customers associated with Enterprise and Premium Merchants within the past 15 minutes.

This can help identify trends and patterns in your log data, and for monitoring the health and performance of your systems.

What to Avoid 🤷‍♂️

This is by far one of the most important topics. If not taken care then this could be a reason for the security leaks. As a rule of thumb, software must not log

1. Credentials
2. HIPPA or GDPR content (PII/PHI)
3. Sensitive information like credit card numbers or social security numbers.
4. API key, auth tokens
5. Encryption or decryption keys

Another useful technique to safeguard the logs is to use Log Redaction. This technique helps in protecting sensitive information or obfuscating it within logs.
Consider the below log

log.info("Record accessed. Patient ID: **** Medical Condition: ****")
log.info("Employee data updated. SSN: *****")

In general, it’s important to avoid logging any information that could pose a security risk to the system or its users.

By following these logging practices, developers can ensure their application is efficient, secure, and well-equipped to handle production environments.

Logging isn’t just about lines of text; it’s about cultivating a disciplined approach to capturing crucial information. You’ll be better equipped to build reliable and robust software products by mastering these practices.

Lastly, to summarise the above knowledge, the following points are to be taken care of

1. Write meaningful log statements. Use the correct log level.
2. Remove Noise and add Signals.
3. Keep a log control mechanism in place.
4. Use a standard logging framework. It provides a consistent way to log messages.
5. Avoid logging sensitive information. This includes things like passwords, credit card numbers, and social security numbers.