search

zalando / go-keyring

Cross-platform keyring interface for Go
MIT License
846 stars 84 forks source link

Suspected race condition in secret service prompt handler #104

Closed williammartin closed 6 months ago

williammartin commented 6 months ago

Description

Hello, I am from the GitHub CLI team and we use this library to store user tokens in secret storage. Historically we've had some issues around the CLI hanging when trying to interact with a secret service and recently we had a number of reports about the CLI failing to use the secret service on the first attempt after machine restart on linux.

After some investigation I believe the culprit is a race condition in how this library handles prompts. I'll explain the investigation in further detail below but the specific issue is in the following code, which runs when an attempt to Unlock results in a prompt: https://github.com/zalando/go-keyring/blob/b0e756d4fd2ce0775d2482c891194fe34cacfbfa/secret_service/secret_service.go#L187-L219

This code makes a call with suffix .Prompt, then registers a MatchSignal for the successful completion of the prompt, at which point it blocks until it receives the signal with name suffix .Completed. Once it receives the signal, unlocking can proceed and secrets can be interacted with.

I believe there is an issue here that the signal handling is registered after the .Prompt call has been made. This leaves a short window for the .Completed response to appear on the dbus before we have registered the handler. Typically, with the user filling in a password this would not be an issue, but if the user has set up automatic unlocking, it appears that the response can come fast enough to trigger a race.

Suggested fix

Naively, I think this is as simple as delaying the .Prompt call until right before we block awaiting the signal. I've opened a PR to demonstrate this: https://github.com/zalando/go-keyring/pull/105

I can't say for sure that it hasn't had some other unintended side effect but we've had three reports that it has resolved the original issue.

More details

In this collapsed section you can find the dbus-monitor log showing two attempts to use gh in a way that accessed the secret service, right after machine restart. Below the details section I will detail the specific lines of interest.

``` signal time=1710441087.030272 sender=org.freedesktop.DBus -> destination=:1.76 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired string ":1.76" signal time=1710441087.030324 sender=org.freedesktop.DBus -> destination=:1.76 serial=4 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost string ":1.76" method call time=1710441095.361593 sender=:1.77 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello method return time=1710441095.361603 sender=org.freedesktop.DBus -> destination=:1.77 serial=1 reply_serial=1 string ":1.77" signal time=1710441095.361606 sender=org.freedesktop.DBus -> destination=(null destination) serial=71 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged string ":1.77" string "" string ":1.77" signal time=1710441095.361610 sender=org.freedesktop.DBus -> destination=:1.77 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired string ":1.77" method call time=1710441095.361697 sender=:1.77 -> destination=org.freedesktop.secrets serial=2 path=/org/freedesktop/secrets; interface=org.freedesktop.DBus.Properties; member=Get string "org.freedesktop.Secret.Service" string "Collections" method return time=1710441095.361955 sender=:1.18 -> destination=:1.77 serial=38 reply_serial=2 variant array [ object path "/org/freedesktop/secrets/collection/kdewallet" ] method call time=1710441095.362390 sender=:1.77 -> destination=org.freedesktop.secrets serial=3 path=/org/freedesktop/secrets; interface=org.freedesktop.Secret.Service; member=Unlock array [ object path "/org/freedesktop/secrets/aliases/default" ] method return time=1710441095.362684 sender=:1.18 -> destination=:1.77 serial=39 reply_serial=3 array [ ] object path "/org/freedesktop/secrets/prompt/p0" method call time=1710441095.362792 sender=:1.77 -> destination=org.freedesktop.secrets serial=4 path=/org/freedesktop/secrets/prompt/p0; interface=org.freedesktop.Secret.Prompt; member=Prompt string "" method return time=1710441095.362801 sender=:1.18 -> destination=:1.77 serial=40 reply_serial=4 signal time=1710441095.362957 sender=:1.18 -> destination=(null destination) serial=41 path=/modules/kwalletd5; interface=org.kde.KWallet; member=walletAsyncOpened int32 1 int32 1966752915 signal time=1710441095.362963 sender=:1.18 -> destination=(null destination) serial=42 path=/modules/kwalletd6; interface=org.kde.KWallet; member=walletAsyncOpened int32 1 int32 1966752915 signal time=1710441095.362965 sender=:1.18 -> destination=(null destination) serial=43 path=/org/freedesktop/secrets; interface=org.freedesktop.Secret.Service; member=CollectionChanged object path "/org/freedesktop/secrets/collection/kdewallet" signal time=1710441095.362967 sender=:1.18 -> destination=:1.77 serial=44 path=/org/freedesktop/secrets/prompt/p0; interface=org.freedesktop.Secret.Prompt; member=Completed boolean false variant array [ object path "/org/freedesktop/secrets/aliases/default" ] method call time=1710441095.362970 sender=:1.77 -> destination=org.freedesktop.DBus serial=5 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch string "type='signal',path='/org/freedesktop/secrets/prompt/p0',interface='org.freedesktop.Secret.Prompt'" method return time=1710441095.362972 sender=org.freedesktop.DBus -> destination=:1.77 serial=3 reply_serial=5 signal time=1710441098.632789 sender=org.freedesktop.DBus -> destination=:1.77 serial=4 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost string ":1.77" signal time=1710441098.632838 sender=org.freedesktop.DBus -> destination=(null destination) serial=72 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged string ":1.77" string ":1.77" string "" method call time=1710441103.840776 sender=:1.78 -> destination=org.freedesktop.DBus serial=1 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=Hello method return time=1710441103.840787 sender=org.freedesktop.DBus -> destination=:1.78 serial=1 reply_serial=1 string ":1.78" signal time=1710441103.840803 sender=org.freedesktop.DBus -> destination=(null destination) serial=73 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged string ":1.78" string "" string ":1.78" signal time=1710441103.840807 sender=org.freedesktop.DBus -> destination=:1.78 serial=2 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameAcquired string ":1.78" method call time=1710441103.840847 sender=:1.78 -> destination=org.freedesktop.secrets serial=2 path=/org/freedesktop/secrets; interface=org.freedesktop.DBus.Properties; member=Get string "org.freedesktop.Secret.Service" string "Collections" method return time=1710441103.841219 sender=:1.18 -> destination=:1.78 serial=45 reply_serial=2 variant array [ object path "/org/freedesktop/secrets/collection/kdewallet" ] method call time=1710441103.841232 sender=:1.78 -> destination=org.freedesktop.secrets serial=3 path=/org/freedesktop/secrets; interface=org.freedesktop.Secret.Service; member=Unlock array [ object path "/org/freedesktop/secrets/aliases/default" ] method return time=1710441103.841579 sender=:1.18 -> destination=:1.78 serial=46 reply_serial=3 array [ object path "/org/freedesktop/secrets/aliases/default" ] object path "/" method call time=1710441103.841591 sender=:1.78 -> destination=org.freedesktop.secrets serial=4 path=/org/freedesktop/secrets/aliases/default; interface=org.freedesktop.Secret.Collection; member=SearchItems array [ dict entry( string "username" string "" ) dict entry( string "service" string "gh:github.com" ) ] method return time=1710441103.841886 sender=:1.18 -> destination=:1.78 serial=47 reply_serial=4 array [ object path "/org/freedesktop/secrets/collection/kdewallet/0" ] method call time=1710441103.841893 sender=:1.78 -> destination=org.freedesktop.secrets serial=5 path=/org/freedesktop/secrets; interface=org.freedesktop.Secret.Service; member=OpenSession string "plain" variant string "" method call time=1710441103.842137 sender=:1.18 -> destination=org.freedesktop.DBus serial=48 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',arg0=':1.78'" method return time=1710441103.842293 sender=:1.18 -> destination=:1.78 serial=49 reply_serial=5 variant array [ ] object path "/org/freedesktop/secrets/session/1" method call time=1710441103.842300 sender=:1.78 -> destination=org.freedesktop.secrets serial=6 path=/org/freedesktop/secrets/collection/kdewallet/0; interface=org.freedesktop.Secret.Item; member=GetSecret object path "/org/freedesktop/secrets/session/1" method return time=1710441103.842411 sender=:1.18 -> destination=:1.78 serial=50 reply_serial=6 struct { object path "/org/freedesktop/secrets/session/1" array [ ] array of bytes "TOKEN-REDACTED" string "text/plain; charset=utf8" } method call time=1710441103.842426 sender=:1.78 -> destination=org.freedesktop.secrets serial=7 path=/org/freedesktop/secrets/session/1; interface=org.freedesktop.Secret.Session; member=Close method return time=1710441103.842569 sender=:1.18 -> destination=:1.78 serial=51 reply_serial=7 method call time=1710441103.842574 sender=:1.18 -> destination=org.freedesktop.DBus serial=52 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=RemoveMatch string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',arg0=':1.78'" method call time=1710441103.842576 sender=:1.18 -> destination=org.freedesktop.DBus serial=53 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=RemoveMatch string "type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameOwnerChanged',arg0='org.freedesktop.DBus'" error time=1710441103.842578 sender=org.freedesktop.DBus -> destination=:1.18 error_name=org.freedesktop.DBus.Error.MatchRuleNotFound reply_serial=53 string "The given match rule wasn't found and can't be removed" signal time=1710441104.135900 sender=org.freedesktop.DBus -> destination=:1.78 serial=3 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost string ":1.78" signal time=1710441104.135944 sender=org.freedesktop.DBus -> destination=(null destination) serial=74 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameOwnerChanged string ":1.78" string ":1.78" string "" ```

In the first usage of gh we see the call to .Unlock returning with a need to prompt:

method call time=1710441095.362390 sender=:1.77 -> destination=org.freedesktop.secrets serial=3 path=/org/freedesktop/secrets; interface=org.freedesktop.Secret.Service; member=Unlock
   array [
      object path "/org/freedesktop/secrets/aliases/default"
   ]
method return time=1710441095.362684 sender=:1.18 -> destination=:1.77 serial=39 reply_serial=3
   array [
   ]
   object path "/org/freedesktop/secrets/prompt/p0"

Immediately after this we see the call to .Prompt:

method call time=1710441095.362792 sender=:1.77 -> destination=org.freedesktop.secrets serial=4 path=/org/freedesktop/secrets/prompt/p0; interface=org.freedesktop.Secret.Prompt; member=Prompt
   string ""
method return time=1710441095.362801 sender=:1.18 -> destination=:1.77 serial=40 reply_serial=4

Then shortly after we see the .Completed response:

signal time=1710441095.362967 sender=:1.18 -> destination=:1.77 serial=44 path=/org/freedesktop/secrets/prompt/p0; interface=org.freedesktop.Secret.Prompt; member=Completed
   boolean false
   variant       array [
         object path "/org/freedesktop/secrets/aliases/default"
      ]

And following that we see the attempt to AddMatch on this interface:

method call time=1710441095.362970 sender=:1.77 -> destination=org.freedesktop.DBus serial=5 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=AddMatch
   string "type='signal',path='/org/freedesktop/secrets/prompt/p0',interface='org.freedesktop.Secret.Prompt'"

3 seconds later (which is the length of time the CLI waits before reporting a timeout), we see the client close:

signal time=1710441098.632789 sender=org.freedesktop.DBus -> destination=:1.77 serial=4 path=/org/freedesktop/DBus; interface=org.freedesktop.DBus; member=NameLost
   string ":1.77"

In the second attempt to use gh, there is no prompt required and everything completes as expected:

method call time=1710441103.842300 sender=:1.78 -> destination=org.freedesktop.secrets serial=6 path=/org/freedesktop/secrets/collection/kdewallet/0; interface=org.freedesktop.Secret.Item; member=GetSecret
   object path "/org/freedesktop/secrets/session/1"
method return time=1710441103.842411 sender=:1.18 -> destination=:1.78 serial=50 reply_serial=6
   struct {
      object path "/org/freedesktop/secrets/session/1"
      array [
      ]
      array of bytes "TOKEN-REDACTED"
      string "text/plain; charset=utf8"
   }