Log HTTP transaction with colors in Deno

In most of the cases, Deno would be running an HTTP server. It is very common to see the HTTP transaction getting summarized and logged in a single line. Generally, the application logging would go in log files. But in some cases, like running locally or simple stand-alone applications, the output would go to console.

In this article, we’ll learn how to summarize and log an HTTP transaction in a single line with colors. We’ll see how to get output like this:

To know about colorful logging in detail, please visit article here.

Imports

To write with colors on console, we need to import standard library’s fmt/colors module.

import * as colors from "https://deno.land/std/fmt/colors.ts";

This import gets all the foreground and backgrounds colors, styling like bold, etc.

Sample application

Here is a very simple application that processes a single route /hello. The successful response is 200 OK for /hello route. All the other routes are responded with 404 Not Found.

import { serve } from "https://deno.land/std/http/mod.ts";
const port = 9000;
async function handleRequest(req: Request) {
  const path = new URL(req.url).pathname;
  let resp: Response;
  if (path === "/hello") {
    resp = new Response(req.body);
  } else {
    resp = new Response(null, { status: 404 });
  }
  return resp;
}
serve(handleRequest, { port });
console.log(`Listening on: http://localhost:${port}`);

Logging function

A new logging function needs to be written that takes three inputs:

• req: The Request object
• resp: The Response object
• time: The time taken to process the request

The logging function would take relevant attributes out of the first two inputs and log them on the console with colors.

Here is an implementation of the logging function that logs the data in a single line with colors:

import * as colors from "https://deno.land/std/fmt/colors.ts";
function logRequest(req: Request, resp: Response, time: number) {
  const c = resp.status >= 500
    ? colors.red
    : resp.status >= 400
    ? colors.yellow
    : colors.green;
  const u = new URL(req.url);
  const qs = u.searchParams.toString();
  console.log(
    `${c(req.method)} ${colors.gray(`(${resp.status})`)} - ${
      colors.cyan(`${u.pathname}${qs ? "?" + qs : ""}`)
    } - ${colors.bold(String(time) + "ms")}`,
  );
}

Updated application

With the logging function in place, we can update the handleRequest function to call the logging function right before sending the response back. The handleRequest function also needs to measure the time taken to process the request.

As the code is not doing much, the response time is 0 or 1ms in most of the cases. To check the logging, an artificial random delay is introduced in the handleRequest function.

Here is the complete code of the updated application:

import { serve } from "https://deno.land/std/http/mod.ts";
import { delay } from "https://deno.land/std/async/mod.ts";
import * as colors from "https://deno.land/std/fmt/colors.ts";
const port = 9000;
function logRequest(req: Request, resp: Response, time: number) {
  const c = resp.status >= 500
    ? colors.red
    : resp.status >= 400
    ? colors.yellow
    : colors.green;
  const u = new URL(req.url);
  const qs = u.searchParams.toString();
  console.log(
    `${c(req.method)} ${colors.gray(`(${resp.status})`)} - ${
      colors.cyan(`${u.pathname}${qs ? "?" + qs : ""}`)
    } - ${colors.bold(String(time) + "ms")}`,
  );
}
async function handleRequest(req: Request) {
  const st = Date.now();
  const path = new URL(req.url).pathname;
  let resp: Response;
  if (path === "/hello") {
    resp = new Response(req.body);
  } else {
    resp = new Response(null, { status: 404 });
  }
  await delay(Math.floor(Math.random() * 100));
  logRequest(req, resp, Date.now() - st);
  return resp;
}
serve(handleRequest, { port });
console.log(`${colors.yellow("Listening on")}: http://localhost:${port}`);

Let’s do a round of testing:

> curl http://localhost:9000
> curl http://localhost:9000/hello
> curl http://localhost:9000/hello -d "hello"
hello> curl http://localhost:900/hello
> 
> curl http://localhost:9000/hello?a=35
> curl http://localhost:9000/hello/dummy
> curl http://localhost:9000/hello/dummy -X DELETE

The logging looks like this:

The following is the same but animated test: