feat: add request logging (#716)

Author: gamemaker1

package.json

@@ -86,6 +86,9 @@
     "source/**/*.ts": [
       "eslint --max-warnings 0 --fix",
       "vitest related --run"
+    ],
+    "tests": [
+      "vitest --run"
     ]
   }
 }

source/main.ts

@@ -114,11 +114,11 @@ for (const endpoint of args['--listen']) {
   let message = chalk.green('Serving!');
   if (local) {
     const prefix = network ? '- ' : '';
-    const space = network ? '            ' : '  ';
+    const space = network ? '    ' : '  ';
 
     message += `\n\n${chalk.bold(`${prefix}Local:`)}${space}${local}`;
   }
-  if (network) message += `\n${chalk.bold('- On Your Network:')}  ${network}`;
+  if (network) message += `\n${chalk.bold('- Network:')}  ${network}`;
   if (previous)
     message += chalk.red(
       `\n\nThis port was picked because ${chalk.underline(

source/types.ts

@@ -75,6 +75,7 @@ export declare interface Options {
   '--single': boolean;
   '--debug': boolean;
   '--config': Path;
+  '--no-request-logging': boolean;
   '--no-clipboard': boolean;
   '--no-compression': boolean;
   '--no-etag': boolean;

source/utilities/cli.ts

@@ -38,12 +38,14 @@ const helpText = chalkTemplate`
 
     -p                                  Specify custom port
 
-    -d, --debug                         Show debugging information
-
     -s, --single                        Rewrite all not-found requests to \`index.html\`
 
+    -d, --debug                         Show debugging information
+
     -c, --config                        Specify custom path to \`serve.json\`
 
+    -L, --no-request-logging            Do not log any request information to the console.
+
     -C, --cors                          Enable CORS, sets \`Access-Control-Allow-Origin\` to \`*\`
 
     -n, --no-clipboard                  Do not copy the local address to the clipboard

source/utilities/logger.ts

@@ -5,12 +5,14 @@
 
 import chalk from 'chalk';
 
+const http = (...message: string[]) =>
+  console.info(chalk.bgBlue.bold(' HTTP '), ...message);
 const info = (...message: string[]) =>
-  console.error(chalk.bgMagenta.bold(' INFO '), ...message);
+  console.info(chalk.bgMagenta.bold(' INFO '), ...message);
 const warn = (...message: string[]) =>
   console.error(chalk.bgYellow.bold(' WARN '), ...message);
 const error = (...message: string[]) =>
   console.error(chalk.bgRed.bold(' ERROR '), ...message);
 const log = console.log;
 
-export const logger = { info, warn, error, log };
+export const logger = { http, info, warn, error, log };

source/utilities/server.ts

@@ -7,8 +7,10 @@ import { readFile } from 'node:fs/promises';
 import handler from 'serve-handler';
 import compression from 'compression';
 import isPortReachable from 'is-port-reachable';
+import chalk from 'chalk';
 import { getNetworkAddress, registerCloseListener } from './http.js';
 import { promisify } from './promise.js';
+import { logger } from './logger.js';
 import type { IncomingMessage, ServerResponse } from 'node:http';
 import type { AddressInfo } from 'node:net';
 import type {
@@ -46,13 +48,37 @@ export const startServer = async (
       type ExpressRequest = Parameters<typeof compress>[0];
       type ExpressResponse = Parameters<typeof compress>[1];
 
+      // Log the request.
+      const requestTime = new Date();
+      const formattedTime = `${requestTime.toLocaleDateString()} ${requestTime.toLocaleTimeString()}`;
+      const ipAddress =
+        request.socket.remoteAddress?.replace('::ffff:', '') ?? 'unknown';
+      const requestUrl = `${request.method ?? 'GET'} ${request.url ?? '/'}`;
+      if (!args['--no-request-logging'])
+        logger.http(
+          chalk.dim(formattedTime),
+          chalk.yellow(ipAddress),
+          chalk.cyan(requestUrl),
+        );
+
       if (args['--cors'])
         response.setHeader('Access-Control-Allow-Origin', '*');
       if (!args['--no-compression'])
         await compress(request as ExpressRequest, response as ExpressResponse);
 
       // Let the `serve-handler` module do the rest.
       await handler(request, response, config);
+
+      // Before returning the response, log the status code and time taken.
+      const responseTime = Date.now() - requestTime.getTime();
+      if (!args['--no-request-logging'])
+        logger.http(
+          chalk.dim(formattedTime),
+          chalk.yellow(ipAddress),
+          chalk[response.statusCode < 400 ? 'green' : 'red'](
+            `Returned ${response.statusCode} in ${responseTime} ms`,
+          ),
+        );
     };
 
     // Then we run the async function, and re-throw any errors.

tests/__snapshots__/cli.test.ts.snap

@@ -27,12 +27,14 @@ exports[`utilities/cli > render help text 1`] = `
 
     -p                                  Specify custom port
 
-    -d, --debug                         Show debugging information
-
     -s, --single                        Rewrite all not-found requests to \`index.html\`
 
+    -d, --debug                         Show debugging information
+
     -c, --config                        Specify custom path to \`serve.json\`
 
+    -L, --no-request-logging            Do not log any request information to the console.
+
     -C, --cors                          Enable CORS, sets \`Access-Control-Allow-Origin\` to \`*\`
 
     -n, --no-clipboard                  Do not copy the local address to the clipboard

tests/server.test.ts

@@ -1,11 +1,12 @@
-// tests/config.test.ts
-// Tests for the configuration loader.
+// tests/server.test.ts
+// Tests for the server creating function.
 
 import { afterEach, describe, test, expect, vi } from 'vitest';
 import { extend as createFetch } from 'got';
 
 import { loadConfiguration } from '../source/utilities/config.js';
 import { startServer } from '../source/utilities/server.js';
+import { logger } from '../source/utilities/logger.js';
 
 // The path to the fixtures for this test file.
 const fixture = 'tests/__fixtures__/server/';
@@ -54,4 +55,46 @@ describe('utilities/server', () => {
     const response = await fetch(address.local!);
     expect(response.ok);
   });
+
+  // Make sure the server logs requests by default.
+  test('log requests to the server by default', async () => {
+    const consoleSpy = vi.spyOn(logger, 'http');
+    const address = await startServer({ port: 3003, host: '::1' }, config, {});
+
+    const response = await fetch(address.local!);
+    expect(response.ok);
+
+    expect(consoleSpy).toBeCalledTimes(2);
+
+    const requestLog = consoleSpy.mock.calls[0].join(' ');
+    const responseLog = consoleSpy.mock.calls[1].join(' ');
+
+    const time = new Date();
+    const formattedTime = `${time.toLocaleDateString()} ${time.toLocaleTimeString()}`;
+    const ip = '::1';
+    const requestString = 'GET /';
+    const status = 200;
+
+    expect(requestLog).toMatch(
+      new RegExp(`${formattedTime}.*${ip}.*${requestString}`),
+    );
+    expect(responseLog).toMatch(
+      new RegExp(
+        `${formattedTime}.*${ip}.*Returned ${status} in [0-9][0-9]? ms`,
+      ),
+    );
+  });
+
+  // Make sure the server logs requests by default.
+  test('log requests to the server by default', async () => {
+    const consoleSpy = vi.spyOn(logger, 'http');
+    const address = await startServer({ port: 3004 }, config, {
+      '--no-request-logging': true,
+    });
+
+    const response = await fetch(address.local!);
+    expect(response.ok);
+
+    expect(consoleSpy).not.toHaveBeenCalled();
+  });
 });