search

keybase / client

Keybase Go Library, Client, Service, OS X, iOS, Android, Electron
BSD 3-Clause "New" or "Revised" License
8.88k stars 1.23k forks source link

My private folder is not re-keying after getting a new computer. #2637

Closed lherlitz closed 8 years ago

lherlitz commented 8 years ago

[write something useful and descriptive here]

my log id: 2c9976ee0664f2186a16ad1c

strib commented 8 years ago

Here's the summary of a slack discussion/investigation:

The result was that kbfs was stuck trying to rekey, and never tried again.

Here are some log snippets. KBFS requesting the promptPaper rekey:

2016-04-17T18:08:31.121761 ▶ [DEBU kbfs(FBO 19ac87e2) folder_branch_ops.go:3506] 3a92 rekeyWithPrompt [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]
2016-04-17T18:08:31.253622 ▶ [DEBU kbfs key_manager.go:383] 3a93 Rekey 19ac87e21c87b78a05cbf23b5c13ca16 (prompt for paper key: true) [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]
2016-04-17T18:08:31.253722 ▶ [DEBU kbfs keybase_daemon_rpc.go:604] 3a94 Flushing cache for user a07730775a4968fb733f0ccd26333519 [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]
2016-04-17T18:08:31.612804 ▶ [DEBU kbfs key_manager.go:240] 3a95 Checking key 0121b9b035fe2117e85a0397ba0091eb0cee8d50c082f6648f83d07c5f235b309b790a [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]
2016-04-17T18:08:31.612863 ▶ [DEBU kbfs key_manager.go:240] 3a96 Checking key 0121259d2a610083c2e308b56d768141fac15d02550cb484ce466afc2baf623dc7690a [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]
2016-04-17T18:08:31.612888 ▶ [DEBU kbfs key_manager.go:240] 3a97 Checking key 0121b2a3b0a30401b0097cc18f98d0f852c1698edd4cb1a0e0efe1be3e0c5b44112a0a [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]
2016-04-17T18:08:31.612909 ▶ [INFO kbfs key_manager.go:243] 3a98 Rekey 19ac87e21c87b78a05cbf23b5c13ca16: adding new device 0121b2a3b0a30401b0097cc18f98d0f852c1698edd4cb1a0e0efe1be3e0c5b44112a0a for user a07730775a4968fb733f0ccd26333519 [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]
2016-04-17T18:08:31.612939 ▶ [INFO kbfs key_manager.go:274] 3a99 Rekey 19ac87e21c87b78a05cbf23b5c13ca16: removing device 01217f0b1ccda6ae42e6b6b2e6e935118ba5530cf065fda9d1f0f630b51e988618710a for user a07730775a4968fb733f0ccd26333519 [tags:REKEYID=kkO7Tuig6VqH3pGiZW5GXw]

(And there are no more entries for that debug tag in the log, which is why I think the RPC to the service never returned.)

Immediately, before getting a response, KBFS requests another folder for rekey:

2016-04-17T18:08:32.332841 ▶ [DEBU kbfs key_manager.go:383] 3a9b Rekey 46589e4d6dc1b34be797353ed2618c16 (prompt for paper key: true) [tags:REKEYID=PEHzCz7qpJIVV5bMKt5bmQ]
...
2016-04-17T18:08:47.379753 ▶ [DEBU kbfs key_manager.go:384] 3b0e Rekey 46589e4d6dc1b34be797353ed2618c16 done: libkbfs.NeedSelfRekeyError{Tlf:"lucherlitz,theob", Public:false} [tags:REKEYID=PEHzCz7qpJIVV5bMKt5bmQ]
2016-04-17T18:08:47.379814 ▶ [DEBU kbfs(FBO 46589e4d) folder_branch_ops.go:3444] 3b0f Device doesn't have access to rekey [tags:REKEYID=PEHzCz7qpJIVV5bMKt5bmQ]
2016-04-17T18:08:47.379841 ▶ [DEBU kbfs(FBO 46589e4d) folder_branch_ops.go:3454] 3b10 Scheduling a rekeyWithPrompt in 10m0s [tags:REKEYID=PEHzCz7qpJIVV5bMKt5bmQ]
2016-04-17T18:08:47.380787 ▶ [DEBU kbfs(FBO 46589e4d) folder_branch_ops.go:3460] 3b11 Rekey bit already set [tags:REKEYID=PEHzCz7qpJIVV5bMKt5bmQ]
2016-04-17T18:08:47.380840 ▶ [DEBU kbfs(FBO 46589e4d) folder_branch_ops.go:3507] 3b12 Done: <nil> [tags:REKEYID=PEHzCz7qpJIVV5bMKt5bmQ]

This one actually does complete, with an error. Perhaps the paper key was entered wrong. Here's what the service is saying around that time:

18912 2016-04-17T18:08:32.329577 ▶ [DEBU keybase crypto.go:272] 37b0 matching paper key: common erode
18913 2016-04-17T18:08:32.329599 ▶ [DEBU keybase handler.go:63] 37b1 SecretUI:GetPassphrase, sessionID = 0
...
19372 2016-04-17T18:08:47.379453 ▶ [DEBU keybase paperkey_phrase.go:87] 397b paper version mismatch: generated paper key version = 14, libkb version = 0
19372 2016-04-17T18:08:47.379554 ▶ [DEBU keybase util.go:386] 397c + UnboxBytes32Any
19373 2016-04-17T18:08:47.412797 ▶ [DEBU keybase log.go:131] 397d {unix} EOF

So I think there might be a problem if KBFS sends two paper key prompt rekeys back-to-back -- it only responds to one of them. Not sure if this is an issue in the service or the GUI. @patrickxb, @cjb what do you think?

strib commented 8 years ago

For the record, we ran into a separate server error in trying to restore this folder, where the folder wasn't being offered as a rekey candidate to a device that might have a paper key available. Then, after fixing that, we ran into another client bug, where after a restart the client was not prompting for a paper key if the rekey bit was already set. @lherlitz gave us permission to just reset his folder to a previous state without the rekey bit set:

BEGIN KEYBASE SALTPACK SIGNED MESSAGE. kXR7VktZdyH7rvq v5wcIkHbrvasvGt LpbnIbldo2ZjMNb ytZAtWG0KThyTfu rVC6JY2Q2HclLgZ 6blRiCIHcatv86H qeyXR1JLqwRD2Lb Ob2JuowlF6flihR jEAtSXSDZnSr5pp W26Ybx0raLbgxMJ 5MDkui5O0P94fTp T3sS26TnebuEmZb p5w2tQzji8pQcmB ax7LXffK6bz2Gor 69mUrDnmFs8SSAr hqUJYeOLENa1Xr9 M6qz2kgf0otaXgB 9AwP0WFLYdzBbFQ Mq9xLc8vb5HQDeN HsMhBg4FBUJ4R7P pNk4dgrBeTi3HYk HomDgkMTOaRveyo vh0wWkfG9KCWUgY nmHTJAqNAHgkgTb fp3Pygwsx60Hv1P R3S2I5nAAsbmbCI YsYyRY4Q9UhHbUy 5uLBs3sEiaA3DNZ cgSIBaKEHb471nM GW. END KEYBASE SALTPACK SIGNED MESSAGE.
patrickxb commented 8 years ago

I think one issue might be that UnboxBytes32AnyArg (and UnboxBytes32Arg) don't set the SessionID field so it defaults to 0. This might be the cause of confusion for the concurrent paper phrase requests if they are on the same connection to the daemon.

strib commented 8 years ago

All the issues discussed here should be fixed in the next public release.

maxtaco commented 8 years ago

Repro'ed bug in which two overlapping unboxBytes32Any calls causes the first guy to be dropped. It looks like Electron is dropping one of the calls. However, it would be a bad UX to have two paper keys prompting at the same time; would be better to single-flight. So we'll solve it with a mutex in the service.

strib commented 8 years ago

@lherlitz told me out-of-band that his private folder is working again. All of the known KBFS bugs are fixed relating to this. I think we're tracking the double-prompt thing separately internally, so closing this.

patrickxb commented 8 years ago

Double prompt fixed in https://keybase.atlassian.net/browse/CORE-2954