morgan icon indicating copy to clipboard operation
morgan copied to clipboard

webscoket request should be logged

Open benzhuo opened this issue 2 years ago • 2 comments

Currently, the web socket request have not been logged by default, but if set the immediate to true, it will be logged . which makes the behavior are not consist, also, if look at the Chrome network, the web socket request is record with 101 status.

benzhuo avatar Feb 23 '23 06:02 benzhuo

Hi! That is very strange, as normally you should not see any logs from Morgan for websoxket requests, as websockets are not something that Express handles at all (and this is an Express middleware).

Would you be able to provide example code that demonstrates what you are seeing? Please list of the versions of things you are using and include instructions for how to reproduce.

dougwilson avatar Feb 23 '23 06:02 dougwilson

Demo code

const express = require('express'); const app = express(); const expressWs = require('express-ws')(app); const morgan = require('morgan'); //http request log const PORT = 3000;

const format=':remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length] B :total-time ms ":referrer" ":user-agent"';

app.use(morgan(format));

app.use(function (req, res, next) { // console.log('middleware'); // req.testing = 'testing'; return next(); }); app.get("/test", (req, res, next) => { // console.log('get route', req.testing); str='' res.send(str) }); app.ws('/websocket', function(ws, req) { ws.on('message', function(msg) { console.log(msg); }); // console.log('socket', req.testing); });

app.listen(PORT, () => { console.log([server] is listening on ${PORT}); });


Reproduce step: 1: Open the URL http://localhost:3000/test the output like below [server] is listening on 3000 ::1 - - [23/Feb/2023:08:39:59 +0000] "GET /test HTTP/1.1" 304 - B 68.212 ms "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/110.0.0.0 Safari/537.36"

2: Modify the line 133 on the morgan index.js file like if (immediate || req.headers.upgrade==='websocket') { Then, run again, the output will be

[server] is listening on 3000 ::1 - - [23/Feb/2023:08:37:11 +0000] "GET /test HTTP/1.1" 304 - B 16.241 ms "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/110.0.0.0 Safari/537.36" ::1 - - [23/Feb/2023:08:37:11 +0000] "GET /websocket/.websocket HTTP/1.1" - - B - ms "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/110.0.0.0 Safari/537.36

The solution that I am seeking that can return a status after server agree to upgrade this request to websocket.

benzhuo avatar Feb 23 '23 08:02 benzhuo