Deubg log for HTTP and HTTPS client errors

bin/genieacs-cwmp.ts

@@ -83,6 +83,7 @@ if (!cluster.worker) {
     host: SERVICE_ADDRESS,
     ssl: key && cert ? { key, cert } : null,
     onConnection: cwmp.onConnection,
+    onClientError: cwmp.onClientError,
     timeout: 30000,
     keepAliveTimeout: 0,
   };

lib/cwmp.ts

@@ -54,6 +54,7 @@ import { decode, encodingExists } from "iconv-lite";
 import { parseXmlDeclaration } from "./xml-parser";
 import * as debug from "./debug";
 import { getRequestOrigin } from "./forwarded";
+import { getSocketEndpoints } from "./server";
 
 const gzipPromisified = promisify(zlib.gzip);
 const deflatePromisified = promisify(zlib.deflate);
@@ -883,16 +884,8 @@ async function sendAcsRequest(
   return writeResponse(sessionContext, res);
 }
 
-// Only needed to prevent tree shaking from removing the remoteAddress
-// workaround in onConnection function.
-const remoteAddressWorkaround = new WeakMap<Socket, string>();
-
 // When socket closes, store active sessions in cache
 export function onConnection(socket: Socket): void {
-  // The property remoteAddress may be undefined after the connection is
-  // closed, unless we read it at least once (caching?)
-  remoteAddressWorkaround.set(socket, socket.remoteAddress);
-
   socket.on("close", async () => {
     const sessionContext = currentSessions.get(socket);
     if (!sessionContext) return;
@@ -947,6 +940,32 @@ export function onConnection(socket: Socket): void {
   });
 }
 
+export function onClientError(err: Error, socket: Socket): void {
+  const remoteAddress = getSocketEndpoints(socket).remoteAddress;
+  localCache
+    .getCurrentSnapshot()
+    .then((cacheSnapshot) => {
+      const debugEnabled = !!localCache.getConfig(
+        cacheSnapshot,
+        "cwmp.debug",
+        {
+          remoteAddress: remoteAddress,
+        },
+        Date.now(),
+        (e) => {
+          if (Array.isArray(e) && e[0] === "FUNC" && e[1] === "REMOTE_ADDRESS")
+            return remoteAddress;
+          return e;
+        }
+      );
+
+      if (debugEnabled) debug.clientError(remoteAddress, err);
+    })
+    .catch((err) => {
+      throw err;
+    });
+}
+
 setInterval(() => {
   if (stats.droppedRequests) {
     logger.warn({

lib/debug.ts

@@ -22,6 +22,7 @@ import { Socket } from "net";
 import { appendFileSync } from "fs";
 import { stringify } from "./common/yaml";
 import * as config from "./config";
+import { getSocketEndpoints } from "./server";
 
 const DEBUG_FILE = "" + config.get("DEBUG_FILE");
 const DEBUG_FORMAT = "" + config.get("DEBUG_FORMAT");
@@ -45,13 +46,14 @@ export function incomingHttpRequest(
   if (!DEBUG_FILE) return;
   const now = new Date();
   const con = httpRequest.socket;
+  const socketEndpoints = getSocketEndpoints(con);
   const msg = {
     event: "incoming HTTP request",
     timestamp: now,
-    remoteAddress: con.remoteAddress,
+    remoteAddress: socketEndpoints.remoteAddress,
     deviceId: deviceId,
     connection: getConnectionTimestamp(con),
-    localPort: con.localPort,
+    localPort: socketEndpoints.localPort,
     method: httpRequest.method,
     url: httpRequest.url,
     headers: httpRequest.headers,
@@ -73,10 +75,11 @@ export function outgoingHttpResponse(
   if (!DEBUG_FILE) return;
   const now = new Date();
   const con = httpResponse.socket;
+  const socketEndpoints = getSocketEndpoints(con);
   const msg = {
     event: "outgoing HTTP response",
     timestamp: now,
-    remoteAddress: con.remoteAddress,
+    remoteAddress: socketEndpoints.remoteAddress,
     deviceId: deviceId,
     connection: getConnectionTimestamp(con),
     statusCode: httpResponse.statusCode,
@@ -199,3 +202,20 @@ export function outgoingUdpMessage(
     appendFileSync(DEBUG_FILE, JSON.stringify(msg) + "\n");
   else throw new Error(`Unrecognized DEBUG_FORMAT option`);
 }
+
+export function clientError(remoteAddress: string, err: Error): void {
+  if (!DEBUG_FILE) return;
+  const now = new Date();
+  const msg = {
+    event: "client error",
+    timestamp: now,
+    remoteAddress: remoteAddress,
+    error: err.message,
+  };
+
+  if (DEBUG_FORMAT === "yaml")
+    appendFileSync(DEBUG_FILE, "---\n" + stringify(msg));
+  else if (DEBUG_FORMAT === "json")
+    appendFileSync(DEBUG_FILE, JSON.stringify(msg) + "\n");
+  else throw new Error(`Unrecognized DEBUG_FORMAT option`);
+}

lib/forwarded.ts

@@ -21,6 +21,7 @@ import { IncomingMessage } from "http";
 import { TLSSocket } from "tls";
 import { parseCIDR, parse, IPv6, IPv4 } from "ipaddr.js";
 import * as config from "./config";
+import { getSocketEndpoints } from "./server";
 
 interface RequestOrigin {
   localAddress: string;
@@ -98,18 +99,19 @@ export function getRequestOrigin(request: IncomingMessage): RequestOrigin {
   let origin = cache.get(request);
   if (!origin) {
     const soc = request.socket;
+    const socketEndpoints = getSocketEndpoints(soc);
     origin = {
-      localAddress: soc.localAddress,
+      localAddress: socketEndpoints.localAddress,
-      localPort: soc.localPort,
+      localPort: socketEndpoints.localPort,
-      remoteAddress: soc.remoteAddress,
+      remoteAddress: socketEndpoints.remoteAddress,
-      remotePort: soc.remotePort,
+      remotePort: socketEndpoints.remotePort,
       host: request.headers["host"],
       encrypted: !!(request.socket as TLSSocket).encrypted,
     };
 
     const header = request.headers["forwarded"];
     if (header) {
-      const ip = parse(soc.remoteAddress) as IPv4;
+      const ip = parse(socketEndpoints.remoteAddress) as IPv4;
       if (cidrs.some((cidr) => ip.match(cidr as [IPv4, number]))) {
         const parsed = parseForwardedHeader(header);
 

lib/nbi.ts

@@ -30,6 +30,7 @@ import { version as VERSION } from "../package.json";
 import { ping } from "./ping";
 import * as logger from "./logger";
 import { flattenDevice } from "./mongodb-functions";
+import { getSocketEndpoints } from "./server";
 
 const DEVICE_TASKS_REGEX = /^\/devices\/([a-zA-Z0-9\-_%]+)\/tasks\/?$/;
 const TASKS_REGEX = /^\/tasks\/([a-zA-Z0-9\-_%]+)(\/[a-zA-Z_]*)?$/;
@@ -101,10 +102,11 @@ export function listener(
   request.addListener("end", () => {
     const body = getBody();
     const urlParts = url.parse(request.url, true);
+    const socketEndpoints = getSocketEndpoints(request.socket);
 
     logger.accessInfo(
       Object.assign({}, urlParts.query, {
-        remoteAddress: request.socket.remoteAddress,
+        remoteAddress: socketEndpoints.remoteAddress,
         message: `${request.method} ${urlParts.pathname}`,
       })
     );

lib/server.ts

@@ -59,8 +59,20 @@ interface ServerOptions {
   timeout?: number;
   keepAliveTimeout?: number;
   onConnection?: (socket: Socket) => void;
+  onClientError?: (err: Error, socket: Socket) => void;
 }
 
+interface SocketEndpoint {
+  localAddress: string;
+  localPort: number;
+  remoteAddress: string;
+  remotePort: number;
+  remoteFamily: "IPv4" | "IPv6";
+}
+
+// Save this info as they're not accessible after a socket has been closed
+const socketEndpoints: WeakMap<Socket, SocketEndpoint> = new WeakMap();
+
 export function start(
   options: ServerOptions,
   _listener: http.RequestListener
@@ -85,6 +97,27 @@ export function start(
     if (options.onConnection) server.on("connection", options.onConnection);
   }
 
+  server.on("connection", (socket: Socket) => {
+    socketEndpoints.set(socket, {
+      localAddress: socket.localAddress,
+      localPort: socket.localPort,
+      remoteAddress: socket.remoteAddress,
+      remotePort: socket.remotePort,
+      remoteFamily: socket.remoteFamily as "IPv4" | "IPv6",
+    });
+  });
+
+  if (options.onClientError) {
+    server.on("clientError", (err, socket: Socket) => {
+      if (err["code"] !== "ECONNRESET" && socket.writable)
+        socket.end("HTTP/1.1 400 Bad Request\r\nConnection: close\r\n\r\n");
+
+      // As per Node docs: This event is guaranteed to be passed an instance
+      // of the <net.Socket> class
+      options.onClientError(err, socket as Socket);
+    });
+  }
+
   server.timeout = options.timeout || 0;
   if (options.keepAliveTimeout != null)
     server.keepAliveTimeout = options.keepAliveTimeout;
@@ -99,3 +132,8 @@ export function stop(): Promise<void> {
     closeServer(20000, resolve);
   });
 }
+
+export function getSocketEndpoints(socket: Socket): SocketEndpoint {
+  // TLSSocket keeps a reference to the raw TCP socket in _parent
+  return socketEndpoints.get(socket["_parent"] ?? socket);
+}