CLI cache is either not working or not significantly reducing time to return a secret

gunzy83
gunzy83
Community Member
edited September 2022 in CLI

Hi,

I have been testing the 1password CLI (along with secrets automation, ssh and other things) for personal things but also with the idea of increasing use at $dayjob and everything is working great except for the CLI when used in interactive scenarios (like Kubernetes ExecCredential and aws credential_process) where the secret needs to be returned regularly and quickly. Obviously if your session has timed out or the desktop app requires unlocking the first access will be slow while you authenticate but the cache should provide fast access to the secret after the first time.

I will quickly outline my setup (identical experience on multiple machines):

  • Manjaro Linux
  • 1password desktop app 8.9.4 (system package)
  • 1password cli 2.7.0 (system package)
  • pam_u2f to use Yubikey to authorise polkit prompts
  • I am based in Australia so I suspect latency may be an issue here with the main 1password endpoints resolving to AWS in Virginia (us-east-1). See below how I came to that conclusion.

My investigation started after I started testing this script that I use in the context of a Kubeconfig file to get the mTLS certificate and key for a k3s cluster. This was fine in Lens (it spawns a kubectl proxy which caches the credential until expiry) but when using the kubectl CLI it makes a request every time and it was a noticeable delay on each request (tab completions are particularly horrible). After testing I discovered that the requests to the 1password CLI (op read) were cumulative and I refactored the script to use only an op item get and then use jq to retrieve the values I needed and create the json blob to be returned. General observation from this, a single secret get command will take between 1.3 and 1.5 seconds to complete.

I started testing this with some canned commands and the time builtin to zsh. I also set export OP_DEBUG=true to run the following:

time op read --cache --account my.1password.com op://Private/e2hylxuji3mpog34p5ngf47uvi/public_key

After a few tests and seeing a noticeable pause in the debug output, I also fired up wireshark and screen recording to see if I could see the client making requests to 1password's servers and see if anything correlates. The following are screenshots from the video and hopefully this will be helpful in working out timings and looking at places that things can be optimised:

First, instant output from the op CLI:

TCP connection open to one of the 1password service IP addresses:

TLS handshake:

The next set of requests/responses appeared seemingly all at once with the log output on the right. At this point the requests to 1password service have taken at least 884m even though the log messages appear to indicate it has found cache hits all round:

Secret returned in 1.426 seconds:

After this there are connections closed in wireshark.

Additional observations:

  • I have also tried this with multiple requests for the same secret and it seems to wait for a response from the 1password servers each time before returning the secret.
  • I just tested pulling username values from items that would definitely not be in the cache and it was consistently taking around 300ms longer (which correlates with another round trip to us-east-1 from my location in Australia).
  • I also noticed that the CLI does not work when you are offline unlike the desktop app. Is this by design?

Overall I think that even if the cache is being used there is a synchronous set of requests to the 1password service that the process will wait for before returning. Can this be looked into please? Please let me know if you require any more details.

Cheers,

Ross Williams.


1Password Version: 8.9.4
Extension Version: Not Provided
OS Version: Manjaro Linux
Browser:_ Chrome/Wavebox (Chromium Based)

Comments

  • gunzy83
    gunzy83
    Community Member

    Sorry about the images, right-click and open in new tab to view.

  • Hi @gunzy83 , thanks for bringing this up! I elevated this internally to make sure we are not missing any significant points of improvement. For now, to try to answer your questions, you might see all those requests if you have biometric plugin enabled and the unlock happens with every command, so a bunch of auth requests are done in the background. Besides that, the CLI does invariably retrieve metadata about your account. Additionally, if the field you are trying to retrieve is a file, an extra request will be made to download that file.

    You are right when saying that the CLI does not work offline like the desktop app, and yes this is intended, at least for now.

    Something to note: caching is enabled by default so when not specifying the cache flag, it will still work in the background. To de-activate it you need to specify --cache=false.

    All the best,
    Andi

  • gunzy83
    gunzy83
    Community Member

    Hi Andi,

    Thanks for the reply. I am now not sure the requests going out to the 1password server have that great an impact and may be a red herring.

    I ran a test of the CLI with OP_BIOMETRIC_UNLOCK_ENABLED=false and did the manual signin. After it was signed in I ran read commands on various entries in my Private vault and found:

    • Cache hits will return in 1.2-1.3 seconds.
    • Cache misses return in ~1.5 seconds.
    • Curiously, all requests showed no activity to the 1password service in Wireshark, including the cache misses (does this mean once you are logged in there is a copy of the DB copied down?).
    • If I disconnect my network the cli complains about not being able to resolve DNS for my.1password.com as expected but curious considering the behaviour above.
    • I noticed this with biometric and without that the CLI pauses right before DEBUG | InitDefaultCache: successfully initialized cache. This seems to indicate that most of the slowness is coming from re-initialisation of the cache (or something else coupled to that step) and my apparent correlation of the requests to this event may have been a red herring. Hopefully that might give a good starting point for debugging.

    Note: my.1password.com has the same list of IP addresses when I perform a DNS lookup from the other day so I did not have to shange my wireshark filter.

    Another curious observation is that there are no requests made to the 1password servers when biometric unlock is waiting on me to respond, it only reaches out after I have clicked allow and then unlocked with my Yubikey via polkit.

    I will leave this with you as I think there is little more I can do on my end other than explore other caching options in between the op cli and kubectl/aws cli. Even at 1.2 seconds the CLI IMO is still too slow for interactive use-cases (particularly when tab-completions are in use) and it should not be this slow if using the local cache. As a comparison, aws eks get-token returns in ~300ms and it reaching out to a web service 1000km away from me.

    Thanks,

    Ross Williams

  • Thanks for the feedback, an internal request for investigating this was filed!

    All the best,
    Andi

This discussion has been closed.