-
Notifications
You must be signed in to change notification settings - Fork 703
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
Remove sync_writes optino for pinniped-proxy cred cache. #5518
Conversation
✅ Deploy Preview for kubeapps-dev ready!
To edit notification comments on pull requests, go to your Netlify site settings. |
}) | ||
.filter(None, LevelFilter::Info) | ||
.init(); | ||
env_logger::Builder::from_default_env().format(|buf, record| { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The key change here (in addition to not needing the extra pretty_env_logger
), is that we're using from_default_env()
so the RUST_LOG
env var is actually used (rather than hard-coding the level above).
Marking this as ready for review, as the other fix is a different change. |
Signed-off-by: Michael Nelson <minelson@vmware.com>
b851165
to
7aff4a7
Compare
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM
Signed-off-by: Michael Nelson <minelson@vmware.com> <!-- Before you open the request please review the following guidelines and tips to help it be more easily integrated: - Describe the scope of your change - i.e. what the change does. - Describe any known limitations with your change. - Please run any tests or examples that can exercise your modified code. Thank you for contributing! --> Follows on from #5518, this time replacing the `cached` package with a custom credential cache. ### Description of the change After further digging, I found that one cause of the slow handling of 50 concurrent requests going through the pinniped-proxy was that: - We were caching a function with an async/await signature which means that even the cached version must have that signature as well - which means a blocking i/o call (which switches the task), and - The `Cached` trait specifies that even a `cache_get` operation mutates the cache (in our case, just for statistics of hits/misses), which, as a result, requires acquiring a *write* lock to the cache to read a cached value. For more details, please see the [discussion with the `Cached` author](jaemk/cached#133). To avoid both of those issues, this PR: 1. Adds a `cache` module that provides a generic read/write `LockableCache` (for multiple readers, single writer) and builds on that with a `PruningCache` that will prune entries (given a test function) when they should no longer be cached, 2. Uses (1) to create a single `CredentialCache` on startup (in `main.rs`) specifically for caching `TokenCredentialRequest` objects and pruning expired entries, and then passes this through for use in different threads concurrently. 3. Uses the cache to fetch the credentials. <!-- Describe the scope of your change - i.e. what the change does. --> ### Benefits Fetching from the cache is now non-blocking (generally, except when an entry is being added) and so leads to less task switching, improving the total query time by ~2s (down to 3-4). There is still something else using significant CPU when creating the client itself (cert-related), which I'm investigating now in a separate PR. <!-- What benefits will be realized by the code change? --> ### Possible drawbacks <!-- Describe any known limitations with your change --> ### Applicable issues <!-- Enter any applicable Issues here (You can reference an issue using #) --> - Ref #5407 ### Additional information <!-- If there's anything else that's important and relevant to your pull request, mention that information here.--> Example log when using `RUST_LOG=info,pinniped_proxy::pinniped=debug` which shows the cache being used after the first request. I've not included it in the output generally, but the cache get is now always under a millisecond. As above, the significant delays (some calls to prepare_and_call_pinniped_exchange only 4ms, others 98ms) are what I'll look at next. ``` 2022-10-27T01:42:47.820245 [INFO] - Listening on http://0.0.0.0:3333 2022-10-27T01:43:05.077116 [DEBUG] - prepare_and_call_pinniped_exchange took 17ms. Used cache?: false 2022-10-27T01:43:05.085273 [INFO] - GET https://kubernetes.default/api?timeout=32s 200 OK 2022-10-27T01:43:05.091663 [DEBUG] - prepare_and_call_pinniped_exchange took 5ms. Used cache?: true 2022-10-27T01:43:05.100437 [INFO] - GET https://kubernetes.default/apis?timeout=32s 200 OK 2022-10-27T01:43:05.106005 [DEBUG] - prepare_and_call_pinniped_exchange took 4ms. Used cache?: true 2022-10-27T01:43:05.209952 [DEBUG] - prepare_and_call_pinniped_exchange took 21ms. Used cache?: true 2022-10-27T01:43:05.299424 [DEBUG] - prepare_and_call_pinniped_exchange took 5ms. Used cache?: true 2022-10-27T01:43:05.311599 [DEBUG] - prepare_and_call_pinniped_exchange took 5ms. Used cache?: true 2022-10-27T01:43:05.493269 [DEBUG] - prepare_and_call_pinniped_exchange took 98ms. Used cache?: true 2022-10-27T01:43:05.593683 [DEBUG] - prepare_and_call_pinniped_exchange took 4ms. Used cache?: true 2022-10-27T01:43:05.604348 [DEBUG] - prepare_and_call_pinniped_exchange took 4ms. Used cache?: true 2022-10-27T01:43:05.697828 [DEBUG] - prepare_and_call_pinniped_exchange took 87ms. Used cache?: true 2022-10-27T01:43:05.811590 [DEBUG] - prepare_and_call_pinniped_exchange took 20ms. Used cache?: true 2022-10-27T01:43:06.004358 [DEBUG] - prepare_and_call_pinniped_exchange took 94ms. Used cache?: true 2022-10-27T01:43:06.098603 [DEBUG] - prepare_and_call_pinniped_exchange took 5ms. Used cache?: true 2022-10-27T01:43:06.108756 [DEBUG] - prepare_and_call_pinniped_exchange took 4ms. Used cache?: true ``` Signed-off-by: Michael Nelson <minelson@vmware.com>
[//]: # (dependabot-start)⚠️ **Dependabot is rebasing this PR**⚠️ Rebasing might not happen immediately, so don't worry if this takes some time. Note: if you make any changes to this PR yourself, they will take precedence over the rebase. --- [//]: # (dependabot-end) Bumps [axios](https://github.com/axios/axios) from 1.3.0 to 1.3.1. <details> <summary>Release notes</summary> <p><em>Sourced from <a href="https://github.com/axios/axios/releases">axios's releases</a>.</em></p> <blockquote> <h2>Release v1.3.1</h2> <h2>Release notes:</h2> <h3>Bug Fixes</h3> <ul> <li><strong>formdata:</strong> add hotfix to use the asynchronous API to compute the content-length header value; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5521">#5521</a>) (<a href="https://github.com/axios/axios/commit/96d336f527619f21da012fe1f117eeb53e5a2120">96d336f</a>)</li> <li><strong>serializer:</strong> fixed serialization of array-like objects; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5518">#5518</a>) (<a href="https://github.com/axios/axios/commit/08104c028c0f9353897b1b6691d74c440fd0c32d">08104c0</a>)</li> </ul> <h3>Contributors to this release</h3> <ul> <li><!-- raw HTML omitted --> <a href="https://github.com/DigitalBrainJS" title="+27/-8 ([#5521](axios/axios#5521) [#5518](axios/axios#5518) )">Dmitriy Mozgovoy</a></li> </ul> </blockquote> </details> <details> <summary>Changelog</summary> <p><em>Sourced from <a href="https://github.com/axios/axios/blob/v1.x/CHANGELOG.md">axios's changelog</a>.</em></p> <blockquote> <h2><a href="https://github.com/axios/axios/compare/v1.3.0...v1.3.1">1.3.1</a> (2023-02-01)</h2> <h3>Bug Fixes</h3> <ul> <li><strong>formdata:</strong> add hotfix to use the asynchronous API to compute the content-length header value; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5521">#5521</a>) (<a href="https://github.com/axios/axios/commit/96d336f527619f21da012fe1f117eeb53e5a2120">96d336f</a>)</li> <li><strong>serializer:</strong> fixed serialization of array-like objects; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5518">#5518</a>) (<a href="https://github.com/axios/axios/commit/08104c028c0f9353897b1b6691d74c440fd0c32d">08104c0</a>)</li> </ul> <h3>Contributors to this release</h3> <ul> <li><!-- raw HTML omitted --> <a href="https://github.com/DigitalBrainJS" title="+27/-8 ([#5521](axios/axios#5521) [#5518](axios/axios#5518) )">Dmitriy Mozgovoy</a></li> </ul> </blockquote> </details> <details> <summary>Commits</summary> <ul> <li><a href="https://github.com/axios/axios/commit/54d3facb3b032665e6ae84e157073702b5c2e4d9"><code>54d3fac</code></a> chore(release): v1.3.1 (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5522">#5522</a>)</li> <li><a href="https://github.com/axios/axios/commit/96d336f527619f21da012fe1f117eeb53e5a2120"><code>96d336f</code></a> fix(formdata): add hotfix to use the asynchronous API to compute the content-...</li> <li><a href="https://github.com/axios/axios/commit/08104c028c0f9353897b1b6691d74c440fd0c32d"><code>08104c0</code></a> fix(serializer): fixed serialization of array-like objects; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5518">#5518</a>)</li> <li>See full diff in <a href="https://github.com/axios/axios/compare/v1.3.0...v1.3.1">compare view</a></li> </ul> </details> <br /> [![Dependabot compatibility score](https://dependabot-badges.githubapp.com/badges/compatibility_score?dependency-name=axios&package-manager=npm_and_yarn&previous-version=1.3.0&new-version=1.3.1)](https://docs.github.com/en/github/managing-security-vulnerabilities/about-dependabot-security-updates#about-compatibility-scores) Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting `@dependabot rebase`. [//]: # (dependabot-automerge-start) [//]: # (dependabot-automerge-end) --- <details> <summary>Dependabot commands and options</summary> <br /> You can trigger Dependabot actions by commenting on this PR: - `@dependabot rebase` will rebase this PR - `@dependabot recreate` will recreate this PR, overwriting any edits that have been made to it - `@dependabot merge` will merge this PR after your CI passes on it - `@dependabot squash and merge` will squash and merge this PR after your CI passes on it - `@dependabot cancel merge` will cancel a previously requested merge and block automerging - `@dependabot reopen` will reopen this PR if it is closed - `@dependabot close` will close this PR and stop Dependabot recreating it. You can achieve the same result by closing it manually - `@dependabot ignore this major version` will close this PR and stop Dependabot creating any more for this major version (unless you reopen the PR or upgrade to it yourself) - `@dependabot ignore this minor version` will close this PR and stop Dependabot creating any more for this minor version (unless you reopen the PR or upgrade to it yourself) - `@dependabot ignore this dependency` will close this PR and stop Dependabot creating any more for this dependency (unless you reopen the PR or upgrade to it yourself) </details> Signed-off-by: dependabot[bot] <support@github.com> Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Bumps [axios](https://github.com/axios/axios) from 1.3.0 to 1.3.1. <details> <summary>Release notes</summary> <p><em>Sourced from <a href="https://github.com/axios/axios/releases">axios's releases</a>.</em></p> <blockquote> <h2>Release v1.3.1</h2> <h2>Release notes:</h2> <h3>Bug Fixes</h3> <ul> <li><strong>formdata:</strong> add hotfix to use the asynchronous API to compute the content-length header value; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5521">#5521</a>) (<a href="https://github.com/axios/axios/commit/96d336f527619f21da012fe1f117eeb53e5a2120">96d336f</a>)</li> <li><strong>serializer:</strong> fixed serialization of array-like objects; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5518">#5518</a>) (<a href="https://github.com/axios/axios/commit/08104c028c0f9353897b1b6691d74c440fd0c32d">08104c0</a>)</li> </ul> <h3>Contributors to this release</h3> <ul> <li><!-- raw HTML omitted --> <a href="https://github.com/DigitalBrainJS" title="+27/-8 ([#5521](axios/axios#5521) [#5518](axios/axios#5518) )">Dmitriy Mozgovoy</a></li> </ul> </blockquote> </details> <details> <summary>Changelog</summary> <p><em>Sourced from <a href="https://github.com/axios/axios/blob/v1.x/CHANGELOG.md">axios's changelog</a>.</em></p> <blockquote> <h2><a href="https://github.com/axios/axios/compare/v1.3.0...v1.3.1">1.3.1</a> (2023-02-01)</h2> <h3>Bug Fixes</h3> <ul> <li><strong>formdata:</strong> add hotfix to use the asynchronous API to compute the content-length header value; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5521">#5521</a>) (<a href="https://github.com/axios/axios/commit/96d336f527619f21da012fe1f117eeb53e5a2120">96d336f</a>)</li> <li><strong>serializer:</strong> fixed serialization of array-like objects; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5518">#5518</a>) (<a href="https://github.com/axios/axios/commit/08104c028c0f9353897b1b6691d74c440fd0c32d">08104c0</a>)</li> </ul> <h3>Contributors to this release</h3> <ul> <li><!-- raw HTML omitted --> <a href="https://github.com/DigitalBrainJS" title="+27/-8 ([#5521](axios/axios#5521) [#5518](axios/axios#5518) )">Dmitriy Mozgovoy</a></li> </ul> </blockquote> </details> <details> <summary>Commits</summary> <ul> <li><a href="https://github.com/axios/axios/commit/54d3facb3b032665e6ae84e157073702b5c2e4d9"><code>54d3fac</code></a> chore(release): v1.3.1 (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5522">#5522</a>)</li> <li><a href="https://github.com/axios/axios/commit/96d336f527619f21da012fe1f117eeb53e5a2120"><code>96d336f</code></a> fix(formdata): add hotfix to use the asynchronous API to compute the content-...</li> <li><a href="https://github.com/axios/axios/commit/08104c028c0f9353897b1b6691d74c440fd0c32d"><code>08104c0</code></a> fix(serializer): fixed serialization of array-like objects; (<a href="https://github-redirect.dependabot.com/axios/axios/issues/5518">#5518</a>)</li> <li>See full diff in <a href="https://github.com/axios/axios/compare/v1.3.0...v1.3.1">compare view</a></li> </ul> </details> <br /> [![Dependabot compatibility score](https://dependabot-badges.githubapp.com/badges/compatibility_score?dependency-name=axios&package-manager=npm_and_yarn&previous-version=1.3.0&new-version=1.3.1)](https://docs.github.com/en/github/managing-security-vulnerabilities/about-dependabot-security-updates#about-compatibility-scores) Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting `@dependabot rebase`. [//]: # (dependabot-automerge-start) [//]: # (dependabot-automerge-end) --- <details> <summary>Dependabot commands and options</summary> <br /> You can trigger Dependabot actions by commenting on this PR: - `@dependabot rebase` will rebase this PR - `@dependabot recreate` will recreate this PR, overwriting any edits that have been made to it - `@dependabot merge` will merge this PR after your CI passes on it - `@dependabot squash and merge` will squash and merge this PR after your CI passes on it - `@dependabot cancel merge` will cancel a previously requested merge and block automerging - `@dependabot reopen` will reopen this PR if it is closed - `@dependabot close` will close this PR and stop Dependabot recreating it. You can achieve the same result by closing it manually - `@dependabot ignore this major version` will close this PR and stop Dependabot creating any more for this major version (unless you reopen the PR or upgrade to it yourself) - `@dependabot ignore this minor version` will close this PR and stop Dependabot creating any more for this minor version (unless you reopen the PR or upgrade to it yourself) - `@dependabot ignore this dependency` will close this PR and stop Dependabot creating any more for this dependency (unless you reopen the PR or upgrade to it yourself) </details> Signed-off-by: dependabot[bot] <support@github.com> Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Signed-off-by: Michael Nelson minelson@vmware.com
Description of the change
This PR is the result of the investigation described on #5407 , the end result of which is a single line removal, though I've left some other changes that were helpful during debugging (logging related).
Benefits
Pinniped-proxy is faster when hit with lots of simultaneous requests.
NOTE: Leaving in draft as although the requests are serviced more quickly in pinniped-proxy, it's still taking 5s for the kubeapps-apis to respond. Investigating why...
Possible drawbacks
None.
Applicable issues
Additional information
After
First request from the barrage of apis starting at around 37.725
First request completing at around 39.956, over 2s after first request began. This is a CPU resource issue.
Last request completing at around 40.232, under 3 seconds after first request began?
So why does API response still take 5s?