Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat(gorouter): add route-service-url to access log #339

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

domdom82
Copy link
Contributor

@domdom82 domdom82 commented Mar 10, 2023

  • A short explanation of the proposed change:

During operations we've found out that it is quite hard to know wether a route uses a route service or not.
The classical example would be a route service like e.g. rate-limiting-service.cf-app.com which is usually hosted on the same CF deployment.
In such a case, the access log would first show this entry:

some-app-that-uses-a-route-service.cf-app.com - [<timestamp>] "GET / HTTP/1.1" 200 0 1750 "-" "<user-agent>" "<src ip>" "<dst ip>" x_forwarded_for:"..." x_forwarded_proto:"https" vcap_request_id:"<uuid>" response_time:0.015462 gorouter_time:0.000058 app_id:"-" app_index:"-" instance_id:"<uuid>" x_cf_routererror:"-"

Gorouter then proceeds to call the route service, which in this case also lives on the same platform, so another gorouter will log something like this:

rate-limiting-service.cf-app.com - [<timestamp>] "GET / HTTP/1.1" 200 0 1750 "-" "<user-agent>" "<src ip>" "<dst ip>" x_forwarded_for:"..." x_forwarded_proto:"https" vcap_request_id:"<uuid>" response_time:0.015462 gorouter_time:0.000058 app_id:"-" app_index:"-" instance_id:"<uuid>" x_cf_routererror:"-"

Unless you add x-forwarded-url to the additional-headers-to-log property, it is basically impossible to correlate the two log statements. If you did that, you would get a hint:

rate-limiting-service.cf-app.com - [<timestamp>] "GET / HTTP/1.1" 200 0 1750 "-" "<user-agent>" "<src ip>" "<dst ip>" x_forwarded_for:"..." x_forwarded_proto:"https" vcap_request_id:"<uuid>" response_time:0.015462 gorouter_time:0.000058 app_id:"-" app_index:"-" instance_id:"<uuid>" x_cf_routererror:"-" x_forwarded_url: "some-app-that-uses-a-route-service.cf-app.com"

Now, if the route service happens to be outside the platform on some external URL, gorouter logs nothing at all. There are some error logs written in proxy_round_tripper but those will either be visible only in debug mode or if an error occurred.
But if everything went fine with the external route service, gorouter would not mention it, leading people to think that response_time_ms applies to the backend app, when in fact it includes a round trip to the route service as well.

  • An explanation of the use cases your change solves

The change proposed adds the route_service_url to access log if the target route has set it.

  • Instructions to functionally test the behavior change using operator interfaces (BOSH manifest, logs, curl, and metrics)

  • Expected result after the change

  • Current result before the change

  • Links to any other associated PRs

  • I have viewed signed and have submitted the Contributor License Agreement

  • I have made this pull request to the main branch

  • I have run all the unit tests using scripts/run-unit-tests-in-docker from routing-release.

  • (Optional) I have run Routing Acceptance Tests and Routing Smoke Tests on bosh lite

  • (Optional) I have run CF Acceptance Tests on bosh lite

@domdom82
Copy link
Contributor Author

note to self: an alternative could be to change the log.Debug statement to log.Info and beef it up with more detail. Maybe that's less intrusive than changing the access log.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Development

Successfully merging this pull request may close these issues.

1 participant