KBFS GUI Copy Error

[blandco]

Attempting to write files (by drag & drop from Desktop to Finder window) to /keybase/blandco/private/

Received the attached error. Attempted this on several different files, all threw errors.

keybase log send sent

my log id: 42faad8cb5642da55a78e21c

[strib]

Hmm. Looks like that directory is a bit messed up:

2016-03-22T23:57:13.054960 ▶ [DEBU kbfs crypto_common.go:253] 1a82d Verify result for 1433-byte message with SignatureInfo{Version: 1, Signature: 07a6cd741c55b06f44315954749e822eaaee80bbed71838613686c3955f407f37218cfb9ac9289a5acf2e1ac91d146b800357743c6e2bacadc841937bf710804, VerifyingKey: 0120d789189c3ae74ff77427e6ae3c461ca83d1a11493631e04d3493aa2247e2934e0a}: Verification failed
2016-03-22T23:57:13.055060 ▶ [DEBU kbfs kbfs_ops.go:187] 1a82e Done: libkb.VerificationError{} [tags:FID=zXKu7i1SwQYs0xLJWxZz7A]
2016-03-22T23:57:13.055116 ▶ [DEBU kbfsfuse dir.go:697] 1a82f Verification failed [tags:FID=zXKu7i1SwQYs0xLJWxZz7A]
2016-03-22T23:57:13.055143 ▶ [DEBU FUSE serve.go:838] 1a830 -> [ID=0xb] Lookup error=EIO: Verification failed

This means that we were unable to verify that the key that supposedly signed the last directory update to /keybase/private/blandco actually signed it. Strangely, the key that supposedly signed it corresponds to your paper key, rib leisure. As far as I know, there should be no way for a paper key to sign a folder update.

@patrickxb: my best guess here is that kbfs asked for a signature from the service, and the service used the device key to sign it, but then returned the paper public key in the info returned by the SignED25519 RPC. Does that sound remotely possible?

Of course, it could also just be that the data we're trying to verify is corrupt, or contains extra data that we no longer put in those data structures (I don't know of anything like that which made it to an external release though).

@blandco: it looks like your log is really big, and keybase log send wasn't able to send us the whole thing. Would it be possible for you to tar/gzip your ~/Library/Logs/keybase.*.log files into a single .tgz and write it to /keybase/private/strib@github,blandco? I'd like to see more about the history of this folder, and what keys were active at what time. Anything you can remember about the last time you wrote to this folder would be helpful as well.

Sorry for the confusion, we'll try to figure out how to fix this as soon as we can.

[strib]

@blandco: Also, it looks like you have two devices. If the one on which you first wrote the folder is different from the one you just sent logs for, I'd like the logs from the other device too, if possible. Basically I want to see logs for the most recent time you wrote to the folder successfully.

[patrickxb]

@strib at first glance, I don't see how that's possible:

sig := *kp.Private.Sign(arg.Msg)
publicKey := kp.Public
ret = keybase1.ED25519SignatureInfo{
    Sig:       keybase1.ED25519Signature(sig),
    PublicKey: keybase1.ED25519PublicKey(publicKey),
}

But I can look into it more tomorrow.

[strib]

Note: I updated a typo my above comment, asking @patrickxb whether a device key could sign something but have the paper public key returned in the siginfo.

[maxtaco]

Still doesn't seem like it, it's the same kp in both cases.

[strib]

Right, but SignED25519 is asking for a signature with libkb.DeviceSigningKeyType -- so how did the paper public key get in the siginfo at all? Certainly the bug could be in kbfs, but the code copying the siginfo into the metadata is pretty simple...

[maxtaco]

BTW, code here

[blandco]

@strib I copied the complete logs to /keybase/private/strib@github,blandco

[maxtaco]

Let's imagine for a moment that getMySecretKey is buggy and is sending a paper key. Then we'd likely still have the paper key in the SigInfo struct, along with the sig generated by the paper key. But would verification still fail since the paper key isn't one of the allowable keys for the user?

[strib]

No, that isn't enough for verification to fail -- and if it was, I think the error message would be different. In this case, the failure is explicitly because the signature could not have been generated for the given data using the given keypair identified in the siginfo. If the key didn't match one of the known verification keys for that user, it would have failed in a different place, with a different error.

[maxtaco]

WE of course haven't ruled out that the signingKey structure in libkb isn't corrupted / mismatched. That would very unexpected, but i guess possible?

[maxtaco]

@strib what's the likelihood of getting any more debugging data here? Presumably the TLF is stuck in a state that we could get the raw signature from the client, but obviously that's hidden info that we don't want to expose in logs by default...

[strib]

@maxtaco @patrickxb: the full logs show that this session is using the rib leisure paper signing key, but the meggo-air device crypt key:

2016-03-19T17:07:19.970639 ▶ [DEBU kbfs keybase_daemon_rpc.go:542] 1d2 new session with username blandco, uid f37842f3d22f43f28a8af32a4ac92919, crypt public key 0121556e37b86e8d46bb5852cc0351b7595dc6195d4f175ce5c60722d532000f01700a, and verifying key 0120d789189c3ae74ff77427e6ae3c461ca83d1a11493631e04d3493aa2247e2934e0a

This strikes me as deeply weird. The full service log should be available under the log ID mentioned above, if you want to take a look.

@maxtaco: we can probably probe our servers to get the MD for this folder, examine the signature, and test it out against different signing keys to see if any of them work. Wouldn't be easy, but we can do it.

[patrickxb]

@strib that is very, very strange. Will look at log again now.

[maxtaco]

Does this logline show up?

   c.log.CDebugf(ctx, "Signed %d-byte message with %s: err=%v", len(msg),
            sigInfo, err)

[strib]

@maxtaco: yep, using the paper signing key:

2016-03-20T01:06:40.371571 ▶ [DEBU kbfs crypto_client.go:86] bba Signed 1176-byte message with SignatureInfo{Version: 1, Signature: 07a6cd741c55b06f44315954749e822eaaee80bbed71838613686c3955f407f37218cfb9ac9289a5acf2e1ac91d146b800357743c6e2bacadc841937bf710804, VerifyingKey: 0120d789189c3ae74ff77427e6ae3c461ca83d1a11493631e04d3493aa2247e2934e0a}: err=<nil> [tags:FID=9Ij1luD9l1sJgNOWLITWPg]

[maxtaco]

Hmm, but still not enough information to see if it's the wrong key or the wrong input msg, right?

[strib]

That's right. However, the first time verification failed, it was with the exact same KBFS version that signed the data, so it's very unlikely that there's complete extra/missing fields in the input message (the only other time I've seen verification fail like this). Of course, there still could be data corruption somewhere.

[maxtaco]

And this is the first observed case of an MD signature with a backup key? Agreed it's highly suspicious!

[strib]

Yes, first one I've noticed.

[strib]

Another data point: /keybase/public/blandco also contains MD updates signed by the paper key, which do verify correctly on my machine. So the service was signing things with the correct private key for at least some of the updates. It's just this one signature that is unverifiable.

[maxtaco]

Are those sigs on either side of the bad sig in terms of time-ordering?

[strib]

Oh wait, hold on, d'oh. I think I'm reading the sigchain wrong. The key in question shows up as the sibkey in the meggo-air device link, but as the kid in the rib leisure device key (which has a different sibkey). Maybe that just means the device key signed the paper key into the chain? If so, very sorry for the confusion!

[patrickxb]

@strib I was just going to write you to ask if you had the key IDs correct for the paper key...meggo-air definitely signed the rib leisure paper key.

[maxtaco]

Check out this page, it's definitely the case that 0120d789189c3ae74ff77427e6ae3c461ca83d1a11493631e04d3493aa2247e2934e0a is a device-key for meggo-air

[strib]

Sorry, I was confused about what "key":"kid" signified in the sigchain link. My bad!

I will have to investigate elsewhere.

[strib]

Something weird is going on with the KBFS data structures. When the MD update is created, the user makes two signatures (corresponding to the "writer" MD and the overall MD):

2016-03-20T01:06:40.371571 ▶ [DEBU kbfs crypto_client.go:86] bba Signed 1176-byt
e message with SignatureInfo{Version: 1, Signature: 07a6cd741c55b06f44315954749e
822eaaee80bbed71838613686c3955f407f37218cfb9ac9289a5acf2e1ac91d146b800357743c6e2
bacadc841937bf710804, VerifyingKey: 0120d789189c3ae74ff77427e6ae3c461ca83d1a1149
3631e04d3493aa2247e2934e0a}: err=<nil> [tags:FID=9Ij1luD9l1sJgNOWLITWPg]
2016-03-20T01:06:40.373105 ▶ [DEBU kbfs crypto_client.go:86] bbb Signed 1403-byt
e message with SignatureInfo{Version: 1, Signature: f2c9f67ac68a98e4892021bf1674
a8e98793f00d1746d6ca7eac606ba161d63076efa6f1f4b0d7c535272e16e2f0ffd71593091dc33a
02a300b656c3bac0530c, VerifyingKey: 0120d789189c3ae74ff77427e6ae3c461ca83d1a1149
3631e04d3493aa2247e2934e0a}: err=<nil> [tags:FID=9Ij1luD9l1sJgNOWLITWPg]

One is 1176 bytes, and the other is 1403 bytes.

Later, when the client tries to verify these, this happens:

2016-03-20T16:24:53.257918 ▶ [DEBU kbfs crypto_common.go:256] 3a80a Verify result for 1176-byte message with SignatureInfo{Version: 1, Signature: 07a6cd741c55b06f44315954749e822eaaee80bbed71838613686c3955f407f37218cfb9ac9289a5acf2e1ac91d146b800357743c6e2bacadc841937bf710804, VerifyingKey: 0120d789189c3ae74ff77427e6ae3c461ca83d1a11493631e04d3493aa2247e2934e0a}: <nil>
...
2016-03-20T16:24:53.260116 ▶ [DEBU kbfs crypto_common.go:253] 3a80c Verify result for 1433-byte message with SignatureInfo{Version: 1, Signature: 07a6cd741c55b06f44315954749e822eaaee80bbed71838613686c3955f407f37218cfb9ac9289a5acf2e1ac91d146b800357743c6e2bacadc841937bf710804, VerifyingKey: 0120d789189c3ae74ff77427e6ae3c461ca83d1a11493631e04d3493aa2247e2934e0a}: Verification failed

Note that it is trying to verify the same signature with two different size buffers! Moreover, the size of the buffer for the second one doesn't match either (1403 bytes vs. 1433 bytes). Not sure how this can happen. Still looking.

[blandco]

I tested from the BigMac device and I receive a similar error when attempting to write to /keybase/private/blandco

I also get this in my shell when I open that location: open /keybase/private/blandco 2016-03-23 13:29:10.172 open[3631:2392658] Metadata.framework [Error]: void _MDItemMarkAsUsedForPath(CFStringRef): was called with a NULL path

Note: The Finder window does open successfully.

[blandco]

@strib Also copied the BigMac logs to keybase-logs-blanco-bigmac.zip

[strib]

Thanks @blandco, found it! It's a KBFS bug. Here's what happened:

1. meggo-air created the folder /keybase/private/blandco initially (revision 1).
2. You then provisioned device BigMac via your PGP key, causing all folders to need to be rekeyed for the new device.
3. BigMac wrote a rekey request as a new revision for the folder (revision 2), which has both the rekey bit and the writer-MD-copied bit set.
4. However, meggo-air was still offline during this time, and didn't do the rekey.
5. 10 minutes later, BigMac gave up waiting and prompted your for your paper key, in order to do the rekeying. Apparently you didn't provide it this time.
6. Another 10 minutes later, you got prompted again, and this time you entered it. This let BigMac write a new revision of the folder (revision 3) including key material for itself.
7. HOWEVER, there is a bug in our code that did not clear the writer-MD-copied bit in this case, which led your client to not re-sign over the new MD, but instead leave the old signature intact, which no longer matches the new MD.

The bug is easy to fix and we will do so right away.

However @blandco, to save your folder we will need to reset it back to revision 1. You won't lose any data (since you haven't written any data yet), but due to the sensitive nature of these folders, we'll need a signed note from you giving us permission to reset your folder. If you agree to this, can you please run the following command and post the results here? Thanks, and sorry for the inconvenience.

keybase sign -m "Please reset folder /keybase/private/blandco (TLF ID 44d8cc18d66544f1324d24aed67c1f16) to revision 1"

[blandco]

Thanks for the help everyone!

BEGIN KEYBASE SALTPACK SIGNED MESSAGE. kXR7VktZdyH7rvq v5wcIkHbsIwijQ8 7nJC15TLB7ZwM6n Ju3bI9BAkrB0auN VTphO470t2GMapH enTpNpOmTI67Fmo 7TA2VyivufvX4Eh AmS4JBwa8FPmbJB kcri4Q5PoFqUcKI 49MYeDQnj2Sdbpr EZQTtgp6rFASn5u QMDLvIzigD3g02Y JS3RorLSGsBmfjs fsJ82iDADmt3KvR JwTZtSmbWfBwEks AP1mMwCIjHsw95y eNoPPoEAeQ1XxwJ LxkNlRrGMGx1cTb A3NyXNkyJwKgcY2 oiDXjgmZwPML0hZ gRbpFxWNNPD8Dpf DVXfcaCfrlZXiKC 3zMafM2JwfmX55u QmfXsHInvvSzcqs B4gWRtWTozpTTqy dp3dWphFtseH0xS czPWtI24CtneycW ov38gvw. END KEYBASE SALTPACK SIGNED MESSAGE.

[strib]

Ok thanks @blando, your TLF has been reset. However, it's still only keyed for your original meggo-air device. The easiest way to cause a rekey (so your other device can read the folder) is to do the following from your meggio-air device:

• Restart KBFS: keybase launchd restart keybase.kbfs.
• ls /keybase/private/blandco -- make sure there are no errors.
• Write a few times to that directory.

Then check it out on BigMac and let us know if everything looks as expected.

[blandco]

@strib Looks good. Thanks for the fix!

[strib]

@blandco: Great! One final thing. We realized that the signed message we asked for above doesn't include the date, which we'd like as well, for the record. So if you get a chance, please post the output of the following command here:

D=`date` keybase sign -m "$D: Please reset folder /keybase/private/blandco (TLF ID 44d8cc18d66544f1324d24aed67c1f16) to revision 1"

Thanks!

[blandco]

@strib Sure thing. Here you go:

BEGIN KEYBASE SALTPACK SIGNED MESSAGE. kXR7VktZdyH7rvq v5wcIkHbsIwijQ8 7nJC15TLB7ZwM6n Ju3bI9BAkrB0auN VTphO470t2PTAQy rAJ34Hpcg0pxrRN FGK76ptQPxrQJVV KXeWHXGCInnIuX6 frDC1uOKqh7sCqZ AYO9rFAI6aYUCyy zfzD73Y9buGeX4g SUW3amqflMskj7d uwuKyDv0v3nAreq p5gT72c9418lra2 OWu727dLgiizPDu it0dqx1NGKXwOTp HEYKP6EL8nAk42E cfiN6jN0RDxFNpN mwail5zRmD8H5HQ MhO4XS48T8RX6Om uNZCjpYxmEmUnfV vPQSxv4AOk9bd3x 0h9JjWmTXqiYSV7 h2JNwtOfsWJkbkt OfkDYn9x4pTQhcI NbzdwLVdgYnexmn v4n5qIpDKBjTRyn 2XS9wdZjcDPdIEy PfKuzE0eCq3vTit dZwp4VtZNH8mdep pg. END KEYBASE SALTPACK SIGNED MESSAGE.

Thanks again for all the help!

[strib]

Thanks, and thanks for bearing with us!