socketio / socketio/socket.io

Log with pino-http middleware raises TypeError: res.on is not a function

Open
#5,072 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug package:engine.io
Dominant language
TypeScript
Stars
63.2k
Forks
10.3k
Avg merge
11d 20h
Merged PRs (30d)
2

Description

Describe the bug
Other app requests get logged with pino-http. Since the express middleware support was added in commit 24786e77c5403b1c4b5a2bc84e2af06f9187f74a, I expected to be able to log using the pino-http. But it crashes on upgrade.

To Reproduce

Engine.IO server version: 6.4.2
pino-http 8.3.3

Server

const engine = require("engine.io");
const logger = require("pino-http")();
const server = engine.listen(3000, {});

server.use(logger);
server.on("connection", (socket) => {
  console.log("connection");

  socket.on("message", (data) => {
    console.log("data", data);
  });

  socket.on("close", () => {
    console.log("close");
  });
});

Engine.IO client version: 6.2.2

Client

const { Socket } = require('engine.io-client');
const socket = new Socket('ws://localhost:3000');

socket.on("open", () => {
  console.log("open");

  socket.on("message", (data) => {
    console.log("data", data);
  });

  socket.on("close", () => {
    console.log("close");
  });
});

Expected behavior
I expected the upgrade request to be logged at upgrade time.

Platform:
Ubuntu 20.04.6, node v18.16.0.

Additional context

$ node server.js
connection
{"level":30,"time":1683554062833,"pid":2257406,"hostname":"ubuntu.mshome.net","req":{"id":1,"method":"GET","url":"/engine.io/?EIO=4&transport=polling&t=OVxf57J&b64=1","headers":{"user-agent":"node-XMLHttpRequest","accept":"*/*","host":"localhost:3000","connection":"close"},"remoteAddress":"::ffff:127.0.0.1","remotePort":36144},"res":{"statusCode":200,"headers":{}},"responseTime":6,"msg":"request completed"}
/home/kohtala/andritz/ava/js/node_modules/pino-http/logger.js:193
        res.on('close', onResponseComplete)
            ^

TypeError: res.on is not a function
    at loggingMiddleware (/home/kohtala/andritz/ava/js/node_modules/pino-http/logger.js:193:13)
    at Array.result (/home/kohtala/andritz/ava/js/node_modules/pino-http/logger.js:89:12)
    at apply (/home/kohtala/andritz/ava/js/node_modules/engine.io/build/server.js:182:32)
    at Server._applyMiddlewares (/home/kohtala/andritz/ava/js/node_modules/engine.io/build/server.js:194:9)
    at Server.handleUpgrade (/home/kohtala/andritz/ava/js/node_modules/engine.io/build/server.js:497:14)
    at Server.<anonymous> (/home/kohtala/andritz/ava/js/node_modules/engine.io/build/server.js:598:26)
    at Server.emit (node:events:513:28)
    at onParserExecuteCommon (node:_http_server:903:14)
    at onParserExecute (node:_http_server:797:3)

Node.js v18.16.0

I can see there is a small WebSocketResponse instead of a real ServerResponse. It does not implement events.

pino-http uses events to postpone the logging until request is complete.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Reproduce the upgrade request with the versions and server/client snippets in the issue, then inspect engine.io/build/server.js around _applyMiddlewares and handleUpgrade. Compare the WebSocketResponse passed during upgrade with the response expected by pino-http/logger.js; done means the upgrade is logged without the res.on TypeError while regular requests still work.

Written by the indexing model from the issue text.

Assessment

Tech stack
javascript, nodejs
Domain
backend, networking
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.