Debug Like a Pro: Writing Logs That Solve Production Mysteries

Poorly written logs can leave you in the dark when trying to debug issues in your backend application. Without crucial information, pinpointing the root cause becomes nearly impossible. Bad logs turn debugging into a guessing game, wasting valuable time and escalating downtime.

The Problem with Generic Logs

Consider the following logging example in a user creation workflow:

if (createUser.password) {
  createUser.password = await bcrypt.hash(createUser.password, 10);
}
console.log(`Creating user ${JSON.stringify(createUser)}`);

const newUser = this.userRepository.create(createUser);
console.log(`User created successfully ${JSON.stringify(newUser)}`);
return await this.userRepository.save(newUser, { reload: true });

Output

Creating user {"email":"test@gmail.com","name":"test","password":"$2b$10$..."} 
User created successfully {"name":"test","password":"$2b$10$...","email":"test@gmail.com"}

Problem: At first glance, these logs might seem sufficient. But as the complexity of the application grows, this approach quickly falls short. Here’s what’s missing: Timestamp, Source, User Context, and Request Correlation.

Transforming Logs into Debugging Powerhouses

By including critical metadata, we can turn generic logs into actionable insights. Here's how the improved logs look:

97048 - 01/15/2025, 5:24:38 PM LOG 0b84a479-1a8e-4a95-96cf-5f31d17793a3 ::1 user@example.com 2025-01-15T12:24:38.492Z users.service.ts:17 Creating user {"email":"test@gmail.com","name":"test","password":"$2b$10$..."}
97048 - 01/15/2025, 5:24:38 PM LOG 0b84a479-1a8e-4a95-96cf-5f31d17793a3 ::1 user@example.com 2025-01-15T12:24:38.493Z users.service.ts:17 User created successfully {"name":"test","password":"$2b$10$...","email":"test@gmail.com"}

Key Improvements:

• Timestamps: Track precisely when events occurred.
• File and Line Number: Identify exact location (e.g., users.service.ts:17).
• User Context: Know who initiated the action.
• Request ID: Trace logs across distributed systems with a unique request ID.

Why This Matters

• Faster Debugging: Pinpoint issues quickly.
• Better Collaboration: Reproduce and understand issues easily.
• Proactive Monitoring: Easier integration with tools like ELK Stack or Datadog.

I've written an example in Node.js using Log4js. Check it out at github.com/habibqureshi/log4jsWithNodejs.