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

Call the offending get_client_config only when required. #5583

Merged
merged 5 commits into from
Nov 21, 2022

Conversation

absoludity
Copy link
Contributor

@absoludity absoludity commented Oct 28, 2022

Signed-off-by: Michael Nelson [email protected]

Reduces the proxying of the ~50 API calls (when the go-lang kubeapps-apis initialises its REST mapper) from 4-6s down to a consistent 1.3-1.6s (on my single computer running a cluster including pinniped-proxy).

Description of the change

After more profiling, the remaining offender was the call to create a kube::Client which ranged from 4-100ms (of CPU + interrupts - not sure if there was any I/O) for every single request. So when 50 requests are issued concurrently, it was starving the CPU available (on my single laptop running a cluster etc.).

The call to create the kube::Client is dependent on the target k8s api server only, so it's easy to cache as the number of different results is equal to the number of clusters targeted by Kubeapps. EDIT: Actually, I just realised we may not even need to cache it, since we can simple move where it's evaluated so we only evaluate it when the token was not cached. I'll try that before marking ready.

Benefits

Pinniped proxy handles the 50 concurrent request/responses in a more reasonable time.

Possible drawbacks

Applicable issues

Additional information

Without this change, the main cause of CPU was the call to get_client_config, which then delays all the proxy requests starting:

2022-10-28T01:53:54.191216 [TRACE] - prepare_and_call_pinniped_exchange took 4ms. Used cache?: true. 4ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T01:53:54.291704 [TRACE] - prepare_and_call_pinniped_exchange took 22ms. Used cache?: true. 22ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T01:53:54.470193 [TRACE] - prepare_and_call_pinniped_exchange took 84ms. Used cache?: true. 84ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T01:53:54.585938 [TRACE] - prepare_and_call_pinniped_exchange took 14ms. Used cache?: true. 14ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T01:53:54.674279 [TRACE] - prepare_and_call_pinniped_exchange took 4ms. Used cache?: true. 4ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T01:53:54.683590 [TRACE] - prepare_and_call_pinniped_exchange took 4ms. Used cache?: true. 4ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T01:53:54.769326 [TRACE] - prepare_and_call_pinniped_exchange took 80ms. Used cache?: true. 80ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.

After the change the call is effectively zero.

2022-10-28T05:28:18.635146 [TRACE] - prepare_and_call_pinniped_exchange took 0ms. Used cache?: true. 0ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T05:28:18.635306 [TRACE] - prepare_and_call_pinniped_exchange took 0ms. Used cache?: true. 0ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T05:28:18.688264 [TRACE] - prepare_and_call_pinniped_exchange took 0ms. Used cache?: true. 0ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T05:28:18.688497 [TRACE] - prepare_and_call_pinniped_exchange took 0ms. Used cache?: true. 0ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.
2022-10-28T05:28:18.692989 [TRACE] - prepare_and_call_pinniped_exchange took 0ms. Used cache?: true. 0ms for get_client_config, 0ms for creating empty cred data, 0ms to fetch the cred.

@absoludity absoludity changed the title Cache the offending get_client_config call in proxy. Call the offending get_client_config only when required. Oct 28, 2022
@absoludity absoludity marked this pull request as ready for review November 2, 2022 19:25
@absoludity absoludity force-pushed the new-pinniped-cache-2 branch from c2149e7 to 733673b Compare November 2, 2022 19:42
Copy link
Contributor

@antgamdia antgamdia left a comment

Choose a reason for hiding this comment

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

Awesome; thanks! It is pretty similar to what was happening in kubeaps-apis. Generating the client is an expensive call that requires plenty of calls and we were creating it each time again and again.

@absoludity
Copy link
Contributor Author

Awesome; thanks! It is pretty similar to what was happening in kubeaps-apis. Generating the client is an expensive call that requires plenty of calls and we were creating it each time again and again.

Yeah - this particular call was a lot less expensive (it's not doing lots of network calls - unlike creating the rest mapper in kubeapps-apis - but when called concurrently 50 times, certainly starving CPU on my system :)

Base automatically changed from new-pinniped-cache-2 to main November 18, 2022 10:31
@netlify
Copy link

netlify bot commented Nov 18, 2022

Deploy Preview for kubeapps-dev canceled.

Name Link
🔨 Latest commit 63beebd
🔍 Latest deploy log https://app.netlify.com/sites/kubeapps-dev/deploys/63775f6f4b771b00090a3051

@absoludity absoludity merged commit 69f5fb5 into main Nov 21, 2022
@absoludity absoludity deleted the pinniped-slowness-3 branch November 21, 2022 01:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Improve response times in Kubeapps APIs when using Pinniped-proxy
3 participants