Allow prepending access log handler for HTTP stream filter

[spacewander]

Commit Message: Allow prepending access log handler for HTTP stream filter
Additional Description: Also change the Golang filter to use this new feature
Risk Level: Low
Testing: Integration
Docs Changes:
Release Notes: Added
Platform Specific Features:
[Optional Runtime guard:]
Fixes #14767
[Optional Fixes commit #PR or SHA]
[Optional Deprecated:]
[Optional API Considerations:]

CC @doujiang24

[repokitteh-read-only]

As a reminder, PRs marked as draft will not be automatically assigned reviewers,
or be handled by maintainer-oncall triage.

Please mark your PR as ready when you want it to be reviewed!

🐱

Caused by: #35595 was opened by spacewander.

see: more, trace.

[spacewander]

The CI failed because of "tar: 91af38e56cd74a0fae3b2155c9ba4469_archive.tar: Cannot write: No space left on device
":
https://dev.azure.com/cncf/envoy/_build/results?buildId=177029&view=logs&jobId=4930ecaf-18f4-5b3c-dea3-309729c3b3ae&j=4930ecaf-18f4-5b3c-dea3-309729c3b3ae&t=ffac7daa-9351-4709-84b9-6a104105ce04

It's not caused by the code.

[zuercher]

/retest

[zuercher]

lgtm, but needs main merged

[spacewander]

lgtm, but needs main merged

@zuercher
Done

[wbpcode]

this is a little late but I doubt if this a best way to do this.

The new interface results in a new problem: we can not ensure the loggers' order base on the filters' order of http_filters configuration.

I think maybe the better way is to make the access logger to be called at end directly.

And other loggers that added by filters will keep their order in filter chain.

This is a behavior change. But I think it's okay and could be guard by a runtime flag.

/wait-any

[spacewander]

this is a little late but I doubt if this a best way to do this.

The new interface results in a new problem: we can not ensure the loggers' order base on the filters' order of http_filters configuration.

I think maybe the better way is to make the access logger to be called at end directly.

And other loggers that added by filters will keep their order in filter chain.

This is a behavior change. But I think it's okay and could be guard by a runtime flag.

/wait-any

The core reason for me to add a new prepend method is that it won't introduce any break change. So it can solve the years-old issue quickly, without more debates.

If a break change is acceptable by several Envoy maintainers, we can also solve this problem by reordering the access log added order.

[wbpcode]

Back compatibility is great. But if it is a detail that no one care or we can prove this new design is better, than I think behavior change is acceptable. I think this is why our change logs have a behavior change list and minor behavior change list.

Our access loggers do nothing except flushing log entries. So, I cannot image any one will depends on current logging order.

A runtime guard is good enough, I think. cc @envoyproxy/senior-maintainers

[zuercher]

Thinking about this some more, I agree this doesn't seem like a great idea. I had just skimmed the discussion in #14767 without much thought.

It seems like putting filter-added access loggers ahead of HCM access loggers (e.g. #14767) makes some sense, but this doesn't actually do that. It just allows filters to puts themselves at the head of the queue.

You've changed the golang test to grab the filter's callback to mutate the StreamInfo during a call to AccessLogHandler::log (notably the StreamInfo passed to log is const so you couldn't do this in an AccessLogHandler that doesn't also happen to be a filter).

It seems to me that golang HTTP filters should modify dynamic metadata during HTTP decoding/encoding rather than trying to mutate the StreamInfo at log time. I don't think we'd allow a C++-only http filter that did this. It may be the case that there should be a way to register a callback on a filter that occurs before AccessLogHandler instances are invoked to indicate a point-in-time when all filters have reached a certain point (e.g. the request is complete) so they can do any final metadata management.

[wbpcode]

We have no way to forbid const_cast in extension implemention. Although this is not good practice and some times may dangerous.

[spacewander]

It may be the case that there should be a way to register a callback on a filter that occurs before AccessLogHandler instances are invoked to indicate a point-in-time when all filters have reached a certain point

There is a callback named onStreamComplete which runs before log(AccessLog::AccessLogType::DownstreamEnd).

So if the log handler is designed to be read-only, the solution may be to let the wasm/Golang filters utilize the onStreamComplete and generate the dynamic metadata here?

[zuercher]

There is a callback named onStreamComplete which runs before log(AccessLog::AccessLogType::DownstreamEnd).

So if the log handler is designed to be read-only, the solution may be to let the wasm/Golang filters utilize the onStreamComplete and generate the dynamic metadata here?

If that callback's invocation meets the needs then yes, that seems like a better implementation that doesn't perform actions that are unexpected in an access logger.

[spacewander]

Surpassed by #35742