DEV Community

Mark Adel
Mark Adel

Posted on

Logging Done Right

Writing effective log messages is crucial for the overall observability of your application. In this guide, we are going to focus mainly on what to log, and how to write effective log messages.

The code examples are written in JavaScript for its simple syntax, but these guidelines are applicable to any programming language.

Let's get started!

1. All log messages should start with the class and function name

logger.info('[MyClass.myFunction] The log message');
Enter fullscreen mode Exit fullscreen mode

Reason: Quickly identifying where the log message comes from. It also adds uniqueness to the logs, ensuring that logs are not duplicated.

2. Add logs in all exception handling blocks

try {
    // code that might throw an error
} catch (error) {
    logger.error('[OrderService.placeOrder] Order placement failed: ' + error.message);
}
Enter fullscreen mode Exit fullscreen mode

Reason: Very crucial for troubleshooting.

3. Include context if useful

logger.warn('[PaymentGateway.processPayment] Payment failed for UserID: 123, OrderID: 456, Error: Insufficient funds');
Enter fullscreen mode Exit fullscreen mode

Reason: Context helps you understand the conditions under which the log was generated, aiding in replicating and fixing issues.

4. Add logs for auditing

logger.info('[OrderService.placeOrder] Order ID: 12345 placed successfully');
Enter fullscreen mode Exit fullscreen mode

Reason: Audit logs have many benefits, such as reconstructing the timeline of a system outage or a security breach, and also being able to detect them while happening.

5. Don't include large log messages if not necessary

Bad:

logger.info('[SomeOrdersJob.processOrders] Finished processing orders chunk, index: ' + chunkIndex + 'orders: ' + JSON.stringify(orders));
Enter fullscreen mode Exit fullscreen mode

Good:

logger.info('[SomeOrdersJob.processOrders] Finished processing orders chunk, index: ' + chunkIndex + 'orders length: ' + orders.length);
Enter fullscreen mode Exit fullscreen mode

Reason: Large log messages reduce readability, consume more space, and might introduce performance implications.

6. Don't log sensitive data

Bad, too bad:

logger.warn('[AuthService.login] User login attempt failed, login data: ' + JSON.stringify(loginData));
Enter fullscreen mode Exit fullscreen mode
logger.warn('[PaymentGateway.registerPaymentCard] Card registration failed, card data: ' + JSON.stringify(cardData));
Enter fullscreen mode Exit fullscreen mode

Good:

logger.warn('[AuthService.login] User login attempt failed, username: ' + loginData.username);
Enter fullscreen mode Exit fullscreen mode

Reason: Logging sensitive data can create security risks and violate privacy regulations such as GDPR. Always sanitize data before logging. It's very likely to overlook sanitizing your data when logging HTTP requests and responses, for example.

7. Use the correct log level

logger.debug('[OrderService.placeOrder] Inside placeOrder function');
logger.info('[OrderService.placeOrder] Order ID: 12345 placed successfully');
logger.warn('[AuthService.login] User login attempt failed, username: ' + loginData.username);
logger.error('[OrderService.placeOrder] Order placement failed: ' + error.message);
logger.fatal('[Database.connect] Unable to connect to the database: ' + error.message);
Enter fullscreen mode Exit fullscreen mode

Reason: Using log levels has many benefits, such as filtering logs based on their level, taking specific actions such as sending an alert for high-severity logs.

8. Timestamp your logs

logger.info('[2024-06-08T12:00:00Z] [OrderService.placeOrder] Order ID: 12345 placed successfully');
Enter fullscreen mode Exit fullscreen mode

Reason: Timestamps provide a chronological order to logs, making it easier to track and understand the sequence of actions. They also allow you to troubleshoot issues that happened at specific times.

9. Avoid logging in loops or recursive functions if not necessary

Bad:

for (let i = 0; i < items.length; i++) {
    logger.info('[InvoiceCalculator.calculate] Calculating item: ' + i);
    // calculation logic
}
Enter fullscreen mode Exit fullscreen mode

Good:

logger.info('[InvoiceCalculator.calculate] Calculation started');
for (let i = 0; i < items.length; i++) {
    // calculation logic
}
logger.info('[InvoiceCalculator.calculate] Calculation finished');
Enter fullscreen mode Exit fullscreen mode

Reason: Excessive log entries make it harder to find relevant information, consume more space, and can lead to performance issues.

10. Log the start and end of long-running operations

logger.info('[DataImportService.importData] Data import started');

// long-running operation

logger.info('[DataImportService.importData] Data import completed');
Enter fullscreen mode Exit fullscreen mode

Reason: It helps you monitor the progress and duration of these operations.

11. Ensure log messages are concise and clear

Bad:

logger.info('[OrderService.placeOrder] The order placement function has successfully completed processing the order with ID 12345');
Enter fullscreen mode Exit fullscreen mode

Good:

logger.info('[OrderService.placeOrder] Order ID: 12345 placed successfully');
Enter fullscreen mode Exit fullscreen mode

Reason: Concise and clear log messages are easier to read and understand.

Conclusion

I hope you found this guide helpful. Please feel free to suggest other practices that you think are important, and I will be happy to include them.

References and Further Reading

Top comments (3)

Collapse
 
lewiscowles1986 profile image
Lewis Cowles

Interesting article; I enjoyed reading it. What do you think about not interpolating data into the log message?

I use structured logging, and find that having a message which I can group-by can help me identify incidence without expensive tooling such as datadog.

Even in expensive tooling; it helps me to be able to write a log message for QA or operations of a system, when it's time for programmers to hand-over.

My only other comment is that I'd probably add method names etc, to be structured as well, rather than as a prefix; similarly with times. That way if I refactor, I can keep stable log identifiers, while the details needed for debugging (which might include file and line-number, or path) are still present.

Collapse
 
aminmansuri profile image
hidden_dude

I would suggest not logging username. Users can often mistake username with password, and that could expose passwords in the log file. Best to avoid that danger. Even though its the user's fault, we need to protect our users.

Collapse
 
markadel profile image
Mark Adel

Good point. Thank you for the addition!