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

logging: add SetFilteredKlogLogger to show client-go throttling logs #673

Merged
merged 1 commit into from
Feb 26, 2024

Conversation

sttts
Copy link
Contributor

@sttts sttts commented Feb 23, 2024

Description of your changes

It's hard to understand which component is causing slowness. This PR enables client throttling logging, both for server-side and client-side, i.e. these pass:

switch {
  case len(retryInfo) > 0:
    message = fmt.Sprintf("Waited for %v, %s - request: %s:%s", latency, retryInfo, r.verb, r.URL().String())
  default:
    message = fmt.Sprintf("Waited for %v due to client-side throttling, not priority and fairness, request: %s:%s", latency, r.verb, r.URL().String())
}

For example:

Waited for 1.033772408s due to client-side throttling, not priority and fairness, request: GET:https://api.example.org/apis/pkg.crossplane.io/v1?timeout=32s
Waited for 580ms, request: GET:https://api.example.org/apis/pkg.crossplane.io/v1?timeout=32s - retries: 1, retry-after: 1s - retry-reason: due to server-side throttling, FlowSchema UID: ""

This is just in Crossplane. It probably needs a log setup helper in controller-runtime and then vendored into providers.

Of course, this information could also be understood from metrics, but metrics are complicated, hard to discover and need tons of knowledge to understand right.

Mr Prosser: But the plans were on display…
Arthur: On display? I eventually had to go down to the cellar to find them.
Mr Prosser: That’s the display department.
Arthur: With a torch.
Mr Prosser: The lights had probably gone out.
Arthur: So had the stairs.
Mr Prosser: But look, you found the notice, didn’t you?
Arthur: Yes yes I did. It was on display at the bottom of a locked filing cabinet stuck in a disused lavatory with a sign on the door saying beware of the leopard.

I have:

  • Read and followed Crossplane's contribution process.
  • Run make reviewable test to ensure this PR is ready for review.

How has this code been tested

Tested in crossplane/crossplane#5419.

@sttts sttts requested review from a team as code owners February 23, 2024 07:51
@sttts sttts requested review from negz and pedjak February 23, 2024 07:51
@sttts sttts force-pushed the sttts-klog-throttling branch 2 times, most recently from 072e15d to c8f2cc9 Compare February 23, 2024 07:58
Copy link
Member

@negz negz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One nit but otherwise LGTM

Comment on lines +15 to +17
// SetFilteredKlogLogger sets log as the logger backend of klog, but filtering
// aggressively to avoid noise.
func SetFilteredKlogLogger(log logr.Logger) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Perhaps this should have something WRT "request throttling" in the name, to make it obvious why it's filtering. Unless you think we might include more in future?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Was thinking that maybe we will add more some day, i.e. this is more like the standard klog setup for crossplane components.

@negz negz merged commit 2c81cc6 into crossplane:master Feb 26, 2024
8 of 9 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants