envoyproxy / envoyproxy/envoy

Lua: Access timing information from handlers

Offen
#8,461 9 Kommentare 0 Reaktionen 0 zugewiesene Personen Auf GitHub ansehen
area/lua design proposal enhancement help wanted
Vorherrschende Sprache
C++
Sterne
28.9k
Forks
5.6k
Ø Merge
1 T. 22 Std.
Gemergte PRs (30 T.)
430

Beschreibung

*Description*:

As previously discussed with @dio in Slack: we would like to access timing information for the current request and response from the Lua filter. This information is not currently available via the Lua API, but it does exist in C++ as stored in the `StreamInfo` class.

I have written [a simple patch](https://github.com/vmg/envoy/commit/6a34e929946c6d7bd3867dc773ad202c711294ff) that exposes the information, but its use in practice is not straightforward: when called from the `envoy_on_request` Lua callback (e.g. `handle:streamInfo():timings()`), the vast majority of the timings are missing, because the Lua filter runs very early in the request lifecycle. In fact, we only have access to the timing for the first received byte for the request.

Even worse: when called from the Lua `envoy_on_response` callback, there are no timings available either: since the response callback also runs very early, and the actual timings for all the events in the response are set on the `StreamInfo` **all at once, at the very end, by calling `setUpstreamTiming`**, we have a strange situation where we're in a response handler and we've already started parsing the response from the upstream (we definitely have access to all the headers), but we don't have access to e.g. how long it took the upstream to send back the first byte of the response.

Right now I'm working around the issue by calling `handle:trailers()` from `envoy_on_response`. In both HTTP/1 and HTTP/2, this method yields the Lua context long enough for Envoy to finish processing the request and setting all the relevant timings. This is not ideal because it significantly increases the time spent in the Lua handler just to be able to access timing information that should be readily available as soon as the handler is called (e.g. the time when the first response byte was received).

I would like to discuss possible ways to work around the issue. One of the options I've discussed with @dio is not exporting all the timings from `streamInfo` and instead exposing a monotonic clock that can be called from Lua, allowing the user to measure whatever intervals they require. Another option would be changing `setUpstreamTiming` to be incremental, so the timings are available in Lua as soon as they're available in C++, but this is not trivial because as stated in the comments, `setUpstreamTiming` is also used in cases where there are several upstream requests in flight and only one can win... But how does this even interact with the Lua filter anyway? Is the Lua `envoy_on_response` callback called once for each request in flight?

Thanks for your help with this!

Beitragsleitfaden

Beitragsleitfaden öffnen

Bewertung

Dieses Issue wurde noch nicht bewertet.

Neue Issues direkt in Ihr Postfach

Eine kurze Übersicht über anfängerfreundliche GitHub-Issues.