Custom Logging Middleware

In our previous lesson, we established the theoretical foundation of grammY's middleware system. You learned about the "Russian Doll" execution model, the flow of control managed by the next() function, and the critical importance of using await to manage the asynchronous nature of the middleware stack.

Today, we transition from theory to practice. You will write your first piece of custom middleware: a simple, yet powerful, logger. This is a foundational skill in backend development, providing essential visibility into your application's behavior for debugging and monitoring. We'll build a function that intercepts every incoming update, logs key information about it, measures how long your bot takes to process it, and then passes control downstream.

The Anatomy of a Logging Middleware

A logging middleware is a perfect first example because it embodies the core principles of the middleware pattern:

• It needs to run for every update, so it will be registered globally with bot.use().
• It must be placed at the very top of the middleware stack to ensure it sees the update first and can measure the total processing time.
• It performs an action before the main logic runs (logging the incoming update).
• It performs an action after all downstream logic completes (logging the processing time).

Let's start by creating the basic structure of our middleware. It's an async function that accepts ctx and next, just as we discussed.

import { Bot, Context, NextFunction } from "grammy";

// The middleware function
async function logger(ctx: Context, next: NextFunction): Promise<void> {
  console.log(`Received update ${ctx.update.update_id}.`);

  // Pass control to the next middleware
  await next();
}

// ... bot setup ...
const bot = new Bot("");

// Register the middleware at the top
bot.use(logger);

// Register other handlers
bot.command("start", (ctx) => ctx.reply("Hello!"));

// ...

In this skeleton, we're simply logging the unique update_id for every incoming update. By placing bot.use(logger) before bot.command("start", ...) we ensure that our logger runs first.

Enhancing the Log Output

A simple "update received" message is a good start, but we can make it far more useful by extracting more details from the Context object. For example, knowing who sent the message and what kind of update it is (text, command, callback query) is crucial for debugging.

Let's expand our logger to include the user's ID and the specific type of the update. The ctx.from object provides user information, and ctx.updateSubTypes() gives a convenient array of strings describing the update content.

async function logger(ctx: Context, next: NextFunction): Promise<void> {
  // Log more details about the incoming update
  console.log(
    `[${new Date().toISOString()}] Received update ${ctx.update.update_id} ` +
    `from user ${ctx.from?.id}. Update subtypes: ${ctx.updateSubTypes().join(", ")}`
  );

  await next();
}

Now, when you run your bot and send it a /start command, you'll see a much more informative log line, something like: [2023-10-27T10:30:00.000Z] Received update 123456789 from user 987654321. Update subtypes: message, text, command. This is already a significant improvement for tracing your bot's activity.

Measuring and Logging Response Time

The real power of the "Russian Doll" model comes from the ability to execute code after await next(). This is how we can measure the total time spent processing an update. You saw the canonical example for this in the previous lesson. Now, let's integrate it into our logger.

The following guide from the official grammY documentation provides the exact pattern for measuring execution time. We will adapt this code directly into our logger.

By merging this logic with our existing logger, we can create a single, comprehensive middleware for both tracing and performance monitoring.

Here is the final, combined middleware function:

async function logger(ctx: Context, next: NextFunction): Promise<void> {
  // 1. Log information about the incoming update
  const startTime = Date.now();
  console.log(
    `[${new Date(startTime).toISOString()}] Processing update ${ctx.update.update_id} from user ${ctx.from?.id}.`
  );

  // 2. Call the next middleware in the chain
  // This is where the actual bot logic will run
  await next();

  // 3. After the bot logic is complete, log the processing time
  const endTime = Date.now();
  console.log(
    `[${new Date(endTime).toISOString()}] Update ${ctx.update.update_id} processed in ${endTime - startTime} ms.`
  );
}

When you place this function in your bot.ts file and register it with bot.use(logger), every interaction with your bot will now produce two log lines: one when the update is first received, and another when it has been fully processed, complete with the duration. This two-phase logging is invaluable for diagnosing slow handlers or understanding the flow of complex interactions.

For a slightly different but equally valid example of a simple middleware, this tutorial shows how to increment a counter in the user's session for every message.

Conclusion

In this lesson, you have successfully translated the theory of middleware into a practical, reusable tool. You built a custom logging middleware that hooks into grammY's processing pipeline to provide visibility and performance metrics for every update your bot receives.

Key Takeaways:

• Custom middleware is created as an async function with the signature (ctx: Context, next: NextFunction).
• You register global middleware using bot.use(), and its position in the code determines its execution order in the middleware stack.
• Code before await next() runs on the "way in," perfect for logging incoming requests.
• Code after await next() runs on the "way out," ideal for tasks like calculating response times.
• The Context object (ctx) is a rich source of information about the user, the message, and the update itself.

You've now moved from simply using middleware (like plugins) to creating it yourself. The next logical step is to build a middleware that doesn't just observe, but actively controls the flow. In our next lesson, you will implement an authentication middleware to restrict bot access to specific users, a critical feature for many bots.