Allow prepending access log handler for WASM filter #35924

sunaydagli · 2024-08-30T18:12:10Z

(Duplicate of #35910, mistakenly did not follow DCO and used wrong fixing command)

Commit Message: Allow prepending access log handler for WASM filter
Additional Description:
Risk Level: Low
Testing: Integration
Docs Changes:
Release Notes:
Platform Specific Features:
Runtime guard: envoy.reloadable_features.prepend_access_log_handler
Fixes #30859

This PR is in response to the approaches considered in ##35595 and #35742 in order to solve #30859. The recommended approach in these discussions was to override onStreamComplete callback, which may make sense for most filters. However, the WASM filter is a unique case in which doing this method would be more of a work-around hack as the filter itself does not inherit StreamFilter, and while the common WASM section does, it cannot utilize the onStreamComplete from its individual filters and thus is missing onStreamComplete, instead using onDone as a proxy for it. As a result, implementing onStreamComplete here would lead to onLog being called within the onStreamComplete method instead of the log() method, which doesn't seem to make the most sense for readability.

As such, we propose to continue the initial decided implementation of prepending the access loggers in order to maintain the execution order. This solution does seem to address this specific problem as described in the issue, so that AccessLogger doesn't see the dynamicMetadata until WASM finishes writing to it. This would be a case specific to WASM because of the details described above. Another WASM implementation is dependent on this issue being fixed, would welcome feedback or approval on this PR.

Signed-off-by: sunaydagli <[email protected]>

repokitteh-read-only · 2024-08-30T18:12:16Z

Hi @sunaydagli, welcome and thank you for your contribution.

We will try to review your Pull Request as quickly as possible.

In the meantime, please take a look at the contribution guidelines if you have not done so already.

🐱

Caused by: #35924 was opened by sunaydagli.

see: more, trace.

repokitteh-read-only · 2024-08-30T18:12:17Z

CC @envoyproxy/runtime-guard-changes: FYI only for changes made to (source/common/runtime/runtime_features.cc).

🐱

Caused by: #35924 was opened by sunaydagli.

see: more, trace.

sunaydagli · 2024-08-30T18:15:47Z

Apologies, I had to open a new PR since I mistakenly used the wrong command to fix GCO issues, please refer to #35910 for previous discussions.

@spacewander, I did consider using the approach you suggested, but since there may be more immediate feature changes to be made, this solution does answer the prior issue in #30859. That being said, if the wasm access log is the more appropriate solution after this is rolled out, we can definitely change it to that approach. I figure since this feature is only used for WASM, it should be safe enough, especially now that it is runtime guard.

@wbpcode thank you for the feedback, I added a runtime guard and added information to the changelog.

Signed-off-by: sunaydagli <[email protected]>

sunaydagli · 2024-08-30T23:54:03Z

FYI: tests failing are the same flakey tests to be addressed in this PR.

wbpcode · 2024-08-31T15:04:29Z

My previous comment is means that we can execute all loggers that be added by the filters before the access loggers. By that way, the order of loggers (added by filters) will still keep consistence with http_filters.

we needn't to add a new prependAccessLogHandler API.

And I didn't get this point:

As a result, implementing onStreamComplete here would lead to onLog being called within the onStreamComplete method instead of the log() method, which doesn't seem to make the most sense for readability.

Why? The onStreamComplete should be only used to tell the wasm filter the current stream is end. And wasm filter could do something in the method.

wbpcode · 2024-08-31T15:05:00Z

/wait

sunaydagli · 2024-08-31T17:58:52Z

My previous comment is means that we can execute all loggers that be added by the filters before the access loggers. By that way, the order of loggers (added by filters) will still keep consistence with http_filters.

we needn't to add a new prependAccessLogHandler API.

And I didn't get this point:

As a result, implementing onStreamComplete here would lead to onLog being called within the onStreamComplete method instead of the log() method, which doesn't seem to make the most sense for readability.

Why? The onStreamComplete should be only used to tell the wasm filter the current stream is end. And wasm filter could do something in the method.

@wbpcode Could you clarify what you mean by executing all loggers that are added by the filters before the access loggers? As in, how would this be done?

For the second point, the WASM context.cc does not override onStreamComplete, because the underlying filter in this directory only generates the filter from a config, and does not actually define the filter with inheriting StreamFilter or StreamFilterBase (from which onStreamComplete is overrode from). The context.cc has a method, onDone(), which seems to be a proxy for this in other methods, as even if the onStreamComplete is implemented, it would not be able to utilize the WASM filter's onStreamComplete in the context.cc implementation. Therefore that's why I thought prepending specifically for WASM would address this issue.

wbpcode · 2024-09-01T12:48:29Z

as even if the onStreamComplete is implemented, it would not be able to utilize the WASM filter's onStreamComplete in the context.cc implementation.

Sorry, I still didn't get it. In my mind, the WASM extension is constructed by two parts: 1. wrapper in the Envoy that is implemented in C++ (Context and code in the proxy-wasm-cpp-host). 2. actual extension logic in the WASM bytes code which could be implemented in any language.

You only need to extend both to implement/provide the onStreamComple or similar things, then it should be work.

Feel free to point it out if I am wrong.

wbpcode · 2024-09-01T12:53:48Z

Could you clarify what you mean by executing all loggers that are added by the filters before the access loggers? As in, how would this be done?

Now, the access loggers (from configuration) and filter loggers (from filters) are store in a single list. And the access loggers will be added first.

So, the finally execution order is the access loggers first.

But it's possible to change it by keeping them in two containers and execute the filter loggers first.

sunaydagli · 2024-09-02T05:42:58Z

as even if the onStreamComplete is implemented, it would not be able to utilize the WASM filter's onStreamComplete in the context.cc implementation.

Sorry, I still didn't get it. In my mind, the WASM extension is constructed by two parts: 1. wrapper in the Envoy that is implemented in C++ (Context and code in the proxy-wasm-cpp-host). 2. actual extension logic in the WASM bytes code which could be implemented in any language.

You only need to extend both to implement/provide the onStreamComple or similar things, then it should be work.

Feel free to point it out if I am wrong.

I believe what you are saying is correct for wasm, but this is for the wasm filter as well, which would be located in this directory. What you are saying to implement/provide onStreamComplete in this area is not possible without significant wasm/http structure changes as if you go through envoy/source/extensions/filters/http, only 1 or 2 have onStreamComplete, and these are usually helper filters that contain or reference another (an example is /match_delegate in that directory) and that allows using the other nested filter's onStreamComplete. If this directory is not to be used for solving the issue at hand, then please let me know. That is why I think this prepend solution works in particular for wasm.

Could you clarify what you mean by executing all loggers that are added by the filters before the access loggers? As in, how would this be done?

Now, the access loggers (from configuration) and filter loggers (from filters) are store in a single list. And the access loggers will be added first.

So, the finally execution order is the access loggers first.

But it's possible to change it by keeping them in two containers and execute the filter loggers first.

To clarify if I am understanding this suggestion properly, do you mean changing the order of this function to have access loggers first? I am unsure where the two containers portion comes into play, would it just mean having two callback lists?

Thanks again for your time for this I appreciate it!

wbpcode · 2024-09-02T06:50:41Z

To clarify if I am understanding this suggestion properly, do you mean changing the order of this function to have access loggers first? I am unsure where the two containers portion comes into play, would it just mean having two callback lists?

I mean you can split the access_log_handlers_ two to different contains. One for filters loggers, one for access loggers. And always iterate the filters loggers first.

envoy/source/common/http/filter_manager.h

Line 1073 in cbfea5b

std::list<AccessLog::InstanceSharedPtr> access_log_handlers_;

phlax · 2024-09-02T15:04:47Z

changelogs/current.yaml

@@ -39,6 +39,14 @@ behavior_changes:
  change: |
    Added new tag extraction so that scoped rds stats have their :ref:'scope_route_config_name
    <envoy_v3_api_msg_config/route/v3/scoped_route>' and stat prefix extracted.
+- area: wasm
+  change: |
+    Added prependAccessLogHandler in HTTP filter to be used by WASM in order to fix


Suggested change

Added prependAccessLogHandler in HTTP filter to be used by WASM in order to fix

Added ``prependAccessLogHandler`` in HTTP filter to be used by WASM in order to fix

phlax · 2024-09-02T15:05:20Z

changelogs/current.yaml

+  change: |
+    Added prependAccessLogHandler in HTTP filter to be used by WASM in order to fix
+    `issue 30859 <https://github.com/envoyproxy/envoy/issues/30859>`_, which allows
+    reversing adding the order of access loggers in order to provide correct dynamic metadata flow


Suggested change

reversing adding the order of access loggers in order to provide correct dynamic metadata flow

reversing the order access loggers are added in order to provide correct dynamic metadata flow

phlax · 2024-09-02T15:05:32Z

changelogs/current.yaml

+    Added prependAccessLogHandler in HTTP filter to be used by WASM in order to fix
+    `issue 30859 <https://github.com/envoyproxy/envoy/issues/30859>`_, which allows
+    reversing adding the order of access loggers in order to provide correct dynamic metadata flow
+    without inheriting onStreamComplete(). This solution is exclusively used by WASM, and may be


Suggested change

without inheriting onStreamComplete(). This solution is exclusively used by WASM, and may be

without inheriting ``onStreamComplete()``. This solution is exclusively used by WASM, and may be

phlax · 2024-09-02T15:05:49Z

changelogs/current.yaml

+    reversing adding the order of access loggers in order to provide correct dynamic metadata flow
+    without inheriting onStreamComplete(). This solution is exclusively used by WASM, and may be
+    changed to an updated WASM access logger if additional features deems it necessary. This behavior can
+    be reverted by setting the runtime guard ``envoy.reloadable_features.prepend_access_log_handler`` to false.


Suggested change

be reverted by setting the runtime guard ``envoy.reloadable_features.prepend_access_log_handler`` to false.

be reverted by setting the runtime guard ``envoy.reloadable_features.prepend_access_log_handler`` to ``false``.

@wbpcode

Commit Message: Change filter and access logger order in access_log_handlers_ Additional Description: Risk Level: Testing: Docs Changes: Release Notes: Platform Specific Features: Runtime guard: envoy.reloadable_features.http_separate_config_and_filter_access_loggers Fixes: #30859 The effect of this change is to iterate the filter loggers first in order for wasm filters to fully write out dynamic metadata before any access loggers use the data, therefore fixing #30859. Thank you to @wbpcode for the suggestion! This change overrides #35924 and related PRs. --------- Signed-off-by: Sunay Dagli <[email protected]> Co-authored-by: sunaydagli <[email protected]>

github-actions · 2024-10-02T16:01:59Z

This pull request has been automatically marked as stale because it has not had activity in the last 30 days. It will be closed in 7 days if no further activity occurs. Please feel free to give a status update now, ping for review, or re-open when it's ready. Thank you for your contributions!

github-actions · 2024-10-09T20:01:22Z

This pull request has been automatically closed because it has not had activity in the last 37 days. Please feel free to give a status update now, ping for review, or re-open when it's ready. Thank you for your contributions!

sunaydagli added 2 commits August 30, 2024 18:06

Full add prependAccessLogHandler

b6bdebd

Signed-off-by: sunaydagli <[email protected]>

Full add prependAccessLogHandler p2

3fb4124

Signed-off-by: sunaydagli <[email protected]>

sunaydagli requested review from wbpcode, tyxia, mattklein123 and yanavlasov as code owners August 30, 2024 18:12

sunaydagli added 2 commits August 30, 2024 18:28

Formatting error

3844d23

Signed-off-by: sunaydagli <[email protected]>

Formatting error p2

b391719

Signed-off-by: sunaydagli <[email protected]>

repokitteh-read-only bot added the waiting label Aug 31, 2024

phlax reviewed Sep 2, 2024

View reviewed changes

phlax assigned kyessenov and wbpcode and unassigned kyessenov Sep 2, 2024

sunaydagli mentioned this pull request Sep 3, 2024

Change filter and access logger order in access_log_handlers_ #35959

Merged

github-actions bot added the stale stalebot believes this issue/PR has not been touched recently label Oct 2, 2024

github-actions bot closed this Oct 9, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Allow prepending access log handler for WASM filter #35924

Allow prepending access log handler for WASM filter #35924

sunaydagli commented Aug 30, 2024

repokitteh-read-only bot commented Aug 30, 2024

repokitteh-read-only bot commented Aug 30, 2024

sunaydagli commented Aug 30, 2024

sunaydagli commented Aug 30, 2024

wbpcode commented Aug 31, 2024 •

edited

Loading

wbpcode commented Aug 31, 2024

sunaydagli commented Aug 31, 2024 •

edited

Loading

wbpcode commented Sep 1, 2024

wbpcode commented Sep 1, 2024

sunaydagli commented Sep 2, 2024

wbpcode commented Sep 2, 2024 •

edited

Loading

phlax Sep 2, 2024

phlax Sep 2, 2024

phlax Sep 2, 2024

phlax Sep 2, 2024

github-actions bot commented Oct 2, 2024

github-actions bot commented Oct 9, 2024

	Added prependAccessLogHandler in HTTP filter to be used by WASM in order to fix
	Added ``prependAccessLogHandler`` in HTTP filter to be used by WASM in order to fix

	reversing adding the order of access loggers in order to provide correct dynamic metadata flow
	reversing the order access loggers are added in order to provide correct dynamic metadata flow

	without inheriting onStreamComplete(). This solution is exclusively used by WASM, and may be
	without inheriting ``onStreamComplete()``. This solution is exclusively used by WASM, and may be

	be reverted by setting the runtime guard ``envoy.reloadable_features.prepend_access_log_handler`` to false.
	be reverted by setting the runtime guard ``envoy.reloadable_features.prepend_access_log_handler`` to ``false``.

Allow prepending access log handler for WASM filter #35924

Allow prepending access log handler for WASM filter #35924

Conversation

sunaydagli commented Aug 30, 2024

repokitteh-read-only bot commented Aug 30, 2024

repokitteh-read-only bot commented Aug 30, 2024

sunaydagli commented Aug 30, 2024

sunaydagli commented Aug 30, 2024

wbpcode commented Aug 31, 2024 • edited Loading

wbpcode commented Aug 31, 2024

sunaydagli commented Aug 31, 2024 • edited Loading

wbpcode commented Sep 1, 2024

wbpcode commented Sep 1, 2024

sunaydagli commented Sep 2, 2024

wbpcode commented Sep 2, 2024 • edited Loading

phlax Sep 2, 2024

Choose a reason for hiding this comment

phlax Sep 2, 2024

Choose a reason for hiding this comment

phlax Sep 2, 2024

Choose a reason for hiding this comment

phlax Sep 2, 2024

Choose a reason for hiding this comment

github-actions bot commented Oct 2, 2024

github-actions bot commented Oct 9, 2024

wbpcode commented Aug 31, 2024 •

edited

Loading

sunaydagli commented Aug 31, 2024 •

edited

Loading

wbpcode commented Sep 2, 2024 •

edited

Loading