hapi icon indicating copy to clipboard operation
hapi copied to clipboard

Unexpected change in request lifecycle in 20.2.1

Open sleroq opened this issue 3 years ago • 4 comments

Support plan

  • is this issue currently blocking your project? (yes/no): yes
  • is this issue affecting a production system? (yes/no): no

Context

  • node version: 18.13.0
  • module version with issue: 20.2.1
  • last module version without issue: 20.2.0
  • environment (e.g. node, browser, native): node
  • used with (e.g. hapi application, another framework, standalone, ...): standalone

What I am trying to achieve

I'm using onRequest and onPostResponse events to open and close connections with database. Expecting onPostResponse to always trigger after onRequest. But in #4295 this behavior changes, and onPostResonse is able to fire before onRequest (if request is aborted).

This behavior does not match with request lifecycle documentation.

Steps to reproduce:

  1. Start simple Hapi server:
const Hapi = require('@hapi/hapi');
const { setTimeout } = require('timers/promises')

const server = Hapi.server({port: 1234});

(async () => {
    server.ext('onRequest', async (req, h) => {
        await setTimeout(1000);
        console.log(`open: ${req.info.id}:${req.path}`);
        return h.continue;
    });

    server.ext('onPostResponse', async (req, h) => {
        console.log(`close: ${req.info.id}:${req.path}`);
        return h.continue;
    });

    await server.start();
})();
  1. Send request, and immediately abort it.
I'm using this go script
package main

import (
	"net/http"
	"os"
	"time"
)

func main() {
	go http.Get("http://localhost:1234")
	time.Sleep(time.Millisecond * 100)
	os.Exit(1)
}

What was the result you got?

close: 1674573013699:sleroq-virtualbox:57890:ldadj8y1:10000:/
open: 1674573013699:sleroq-virtualbox:57890:ldadj8y1:10000:/

What result did you expect?

open: 1674572975830:sleroq-virtualbox:57346:ldadifmt:10000:/
close: 1674572975830:sleroq-virtualbox:57346:ldadifmt:10000:/

sleroq avatar Jan 24 '23 15:01 sleroq

This was supposed to be a bug, marked as support by mistake.

sleroq avatar Jan 24 '23 21:01 sleroq

@nargonath

Sorry for mentioning directly, I believe this issue is being neglected because of the wrong label.

sleroq avatar Feb 06 '23 14:02 sleroq

This is pretty tricky— if the request is aborted, then onPostResponse happens at that moment since that is when the request has settled. There are equally use-cases where you want the "finalize response" steps (quoting the docs) to occur immediately. The docs even take a moment to note that you may want your onPostResponse handlers to defer asynchronous work so that they can all be called immediately when the request settles.

So that's the tension: on one hand, the finalize response steps and onPostResponse should occur as soon as the request settles; on the other hand, if there's a lifecycle method that is still running at that moment (which is likely) then of course there's no reliable way to cause it to terminate immediately. The onRequest extension should still begin before onPostResponse, which might be the most we can really guarantee for the case of an aborted request.

At the same time, I totally see how this poses an issue for you. My recommendation would be to handle this case by checking if the request is active after you setup the database connection, and if it isn't then you can tear it down immediately:

    server.ext('onRequest', async (req, h) => {
        req.app.db = await setupDbConnection();
        if (!req.active()) {
            await req.app.db.close();
        }
        return h.continue;
    });

devinivy avatar Feb 06 '23 15:02 devinivy

Thank you for the explanation.

I agree that both variants are acceptable. However, it seems odd to me to make this change in the patch version.

If this change was intentional, then I believe the issue is resolved.

sleroq avatar Feb 07 '23 10:02 sleroq