http/2 timings

[etnbrd]

Describe the bug

• Node.js version: v17.0.1
• OS & version: Darwin Kernel Version 20.6.0, macOS Big Sur 11.6.1 (20G224)

When issuing a request to an http/2 server, the response miss the lookup, connect and secureConnect timings, which in turn prevents the computing of the request timing.

I couldn't find any reference in the existing issues. If there is one I missed, feel free to link it and close this issue.

Code to reproduce

Here is a PR with a failing unit test reproducing the issue: #1957

Checklist

• I have read the documentation.
• I have tried my code with the latest version of Node.js and Got.

[etnbrd]

My understanding is that, with http2: true, got uses by default the http2-wrapper.auto as the request function (here), which returns an http2-wrapper.ClientRequest. This in turns emits a proxy around the ClientRequest stream (here), rather than a socket, like http-timer would expect (here), hence http-timer discards this proxied stream (here).

I guess http-timer is already aware of this proxy possibly returned by http2-wrapper.auto and voluntarily discards it as it'd be impossible to get the missing timings from it anyway: the lookup, connect and secureConnect events were emitted during creation of the http2-wrapper.ClientRequest which established the socket, whereas the http-timer is initialized when receiving the request (here), after the socket is established.

So I guess that to support the missing timings in http/2, the timer would have to be initialized before, to include the calling of the request function. But you probably have a way better understanding of it all than me anyway 😅

[szmarczak]

Good catch! One solution would be to set lookup, connect / secureConnect to 0. Would you be up to fixing this?

[etnbrd]

You mean to set these timestamps to be the same as socket before returning, in case it's a proxy, in http-timer (here)?
I could do that, but wouldn't it be preferable to report the actual timings during the request function? I started implementing that outside of got. I might be able to port it in got.

[szmarczak]

You mean to set these timestamps to be the same as socket

Yep.

wouldn't it be preferable to report the actual timings during the request function?

It isn't worth it since the sockets will be reused.

[etnbrd]

Ah, you mean because of the http2-agent, the sockets (http2 sessions) will be reused between requests, so the timings would make sense only for the first request and the establishing of the session, not for the subsequent requests, right?

But isn't it the same with http/1? The sockets are reused, and yet, the timings are populated as expected. At least for the first request, didn't check subsequent requests.
I think it'd be worth it to have on par features with http/1, although it might not be trivial indeed.

[szmarczak]

the timings would make sense only for the first request and the establishing of the session, not for the subsequent requests, right?

Right.

isn't it the same with http/1?

It is, however you do not have sessions in HTTP/1. You can't tell the timings using a session. We would have to use a WeakMap in http2-wrapper and record those sockets. It's not worth it, too many modifications. It would be better if Node.js implemented this.

[etnbrd]

Hum, I had the understanding that there is a 1:1 mapping between HTTP2 Session and its underlying sockets (loosely caught from this part of the node documentation). But given TLS session can be resumed, I guess there might be several sockets associated with one session (but not two at the same time), right?

Regarding the initial issue, if we can't have the timings from an HTTP/2 request, then I guess it would make more sense to me to leave them as undefined, to avoid any confusion between super-fast connection and unavailable timing. So I could send a PR just to avoid request ending up as NaN, and keep it undefined if neither connect nor secureConnect are available.

Now, I would still like to get the timings from the http2 session, even if only for the first socket. But maybe the implementation of this feature would rather belong in http2-wrapper?

[szmarczak]

Hum, I had the understanding that there is a 1:1 mapping between HTTP2 Session and its underlying sockets

This is correct.

But given TLS session can be resumed, I guess there might be several sockets associated with one session (but not two at the same time), right?

A single TLS session can be used multiple times at once.

I guess it would make more sense to me to leave them as undefined, to avoid any confusion between super-fast connection and unavailable timing.

That would work as well.

I would still like to get the timings from the http2 session, even if only for the first socket. But maybe the implementation of this feature would rather belong in http2-wrapper?

That's rather not currently possible. http2-wrapper performs ALPN negotiation and the ClientRequest stream is returned asynchronusly for simplicity. We would have to return it synchronusly, which means we would have to add another layer in order for mimicking ClientRequest. We want the socket event from it. So instead:

const request = await http2.auto('https://example.com');
console.log(Boolean(request.socket)); // true

we would do:

const request = http2.auto('https://example.com');
console.log(Boolean(request.socket)); // false

Making this feature http2-wrapper specific is a no-go. It would just add more complexity since we would have to handle HTTP/1 and HTTP/2 separately. The goal of http2-wrapper is to provide an API which is almost identical to HTTP/1. Measuring timings is out of its scope. However the solution above would do.