Debugging and logging techniques

Debugging and Logging Techniques

Debugging and logging are indispensable parts of the development process, especially when using Mongoose for MongoDB operations. Proper debugging and logging can help quickly identify issues and improve development efficiency. Below are some practical tips and examples.

Enabling Mongoose Debug Mode

Mongoose has built-in debugging functionality, which can be enabled by setting the debug option. Once enabled, Mongoose will output all executed queries and operations to the console.

const mongoose = require('mongoose');
mongoose.set('debug', true);

// Connect to the database
mongoose.connect('mongodb://localhost:27017/test', {
  useNewUrlParser: true,
  useUnifiedTopology: true,
});

After enabling debug mode, the console will output content similar to the following:

Mongoose: users.insertOne({ name: 'John', age: 30, _id: ObjectId("..."), __v: 0 })

Customizing Log Output

If the default debug output is not detailed enough, you can customize the log output by listening to Mongoose's debug event.

mongoose.set('debug', function(collectionName, method, query, doc) {
  console.log(`Mongoose: ${collectionName}.${method}`, JSON.stringify(query), doc);
});

This allows you to format the logs as needed, such as adding timestamps or filtering specific operations.

Using Middleware to Log Operations

Mongoose middleware (pre/post hooks) can be used to log model operations. For example, logging before and after saving a document:

const userSchema = new mongoose.Schema({
  name: String,
  age: Number,
});

userSchema.pre('save', function(next) {
  console.log(`About to save user: ${this.name}`);
  next();
});

userSchema.post('save', function(doc) {
  console.log(`User saved: ${doc.name}`);
});

const User = mongoose.model('User', userSchema);

Logging Query Execution Time

For performance-sensitive queries, you can log the execution time to help optimize performance.

const start = Date.now();
User.find({ age: { $gt: 25 } })
  .then(users => {
    const duration = Date.now() - start;
    console.log(`Query took ${duration}ms`);
    console.log(users);
  })
  .catch(err => console.error(err));

Using Winston or Morgan for Logging

For production environments, you can use professional logging libraries like Winston or Morgan to log Mongoose operations.

const winston = require('winston');

const logger = winston.createLogger({
  level: 'info',
  transports: [
    new winston.transports.Console(),
    new winston.transports.File({ filename: 'mongoose.log' }),
  ],
});

mongoose.set('debug', function(collectionName, method, query, doc) {
  logger.info(`Mongoose: ${collectionName}.${method}`, { query, doc });
});

Error Logging

Errors in Mongoose operations need to be properly logged for later troubleshooting. You can log errors in Promise catch blocks or try-catch blocks.

User.findById('someId')
  .then(user => {
    if (!user) {
      throw new Error('User not found');
    }
    console.log(user);
  })
  .catch(err => {
    logger.error('Error fetching user', { error: err.message });
  });

Using Mongoose Log Levels

Mongoose's debug option supports passing a function, allowing you to set different log levels based on the operation type (e.g., query, update, delete).

mongoose.set('debug', function(collectionName, method, query, doc, options) {
  const level = method === 'delete' ? 'warn' : 'info';
  logger.log(level, `Mongoose: ${collectionName}.${method}`, { query, doc });
});

Logging Slow Queries

You can use middleware or global settings to log queries that take too long to execute.

const slowQueryThreshold = 100; // 100ms

mongoose.set('debug', function(collectionName, method, query, doc, options) {
  const start = Date.now();
  return function() {
    const duration = Date.now() - start;
    if (duration > slowQueryThreshold) {
      logger.warn(`Slow query: ${collectionName}.${method} took ${duration}ms`, { query });
    }
  };
});

Integrating with Sentry or Similar Tools

For production environments, you can integrate Mongoose error logs with error monitoring tools like Sentry.

const Sentry = require('@sentry/node');

User.findById('invalidId')
  .then(user => console.log(user))
  .catch(err => {
    Sentry.captureException(err);
    logger.error('Error in User.findById', { error: err.message });
  });

Log Filtering and Sanitization

When logging, be mindful of sanitizing sensitive information (e.g., passwords).

mongoose.set('debug', function(collectionName, method, query, doc) {
  const sanitizedQuery = JSON.parse(JSON.stringify(query));
  if (sanitizedQuery.password) {
    sanitizedQuery.password = '***';
  }
  logger.info(`Mongoose: ${collectionName}.${method}`, { query: sanitizedQuery });
});

Using Environment Variables to Control Log Levels

Dynamically adjust log levels based on the environment (development, testing, production).

const isProduction = process.env.NODE_ENV === 'production';

mongoose.set('debug', isProduction ? false : true);

Logging Connection Status

Mongoose connection events (e.g., connected, disconnected) can also be logged.

mongoose.connection.on('connected', () => {
  logger.info('Mongoose connected to MongoDB');
});

mongoose.connection.on('error', err => {
  logger.error('Mongoose connection error', { error: err.message });
});

mongoose.connection.on('disconnected', () => {
  logger.warn('Mongoose disconnected from MongoDB');
});

Debugging Queries with Mongoose's lean()

lean() skips Mongoose's document conversion and returns plain JavaScript objects. This is useful for debugging query performance.

User.find({ age: { $gt: 25 } })
  .lean()
  .then(users => {
    console.log('Lean query result:', users);
  })
  .catch(err => console.error(err));

Logging Bulk Operations

For bulk operations (e.g., insertMany, updateMany), you can log the number of affected documents.

User.insertMany([{ name: 'Alice' }, { name: 'Bob' }])
  .then(docs => {
    logger.info(`Inserted ${docs.length} users`);
  })
  .catch(err => logger.error('Error in insertMany', { error: err.message }));