dougmoscrop / serverless-http

Use your existing middleware framework (e.g. Express, Koa) in AWS Lambda 🎉
Other
1.71k stars 164 forks source link

feat: Emit close event on http.ServerResponse #263

Closed astuyve closed 1 year ago

astuyve commented 1 year ago

I want to preface this with the fact that I don't know much about the Node internals patched by this library here, so please do help me correct any misunderstandings as I'm sure there are several.

I ran into an issue in dd-trace where an instance of http.ServerResponse emitted only finish and not close. Based on my understanding of the docs, we'd expect to see finish and close after an instance of http.ServerResponse has finished and the response written to the network interface.

To verify that understanding, I wrote a tiny webserver and confirmed the behavior:

'use strict'
const http = require('http')

const myListener = (req, res) => {
  res.on('close', () => { console.log('response received close') })
  res.on('finish', () => { console.log('response received finish') })
  res.writeHead(200)
  res.end(JSON.stringify({receivedRequest: true}))
}

const server = http.createServer(myListener)
server.listen(1337, '127.0.0.1', () => { console.log('running') })
image

However, while tracking down this issue, I noticed that running this library (with express, specifically) within a lambda function doesn't emit close when the response is finished. Rather only finish is emitted from the http.ServerResponse. This caused Datadog to buffer traces (as our APM telemetry didn't think the response was done), and never flush.

I fixed this on our side here, but I wanted to fix this upstream.

If I understand correctly, Node should automatically emit close when the socket receives close, but that doesn't happen here as our socket doesn't ever really close.

Here's a similar implementation which manually plumbs a socket to a response, where they call socket.end() when response#finish is received; so this is the route I chose here.

zoellner commented 1 year ago

This change seems to have had a probably unintended side effect: I am using serverless-http with express and the logger pino-http. Starting at serverless-http@3.1.1 I am seeing all request logs getting logged twice. I added a super minimal demo project here to show the issue: https://github.com/zoellner/serverless-http-pino-bug