keybase / client

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

Gracefully shutdown kbfs when still writing files #14281

Open sudoapt-getclean opened 5 years ago

sudoapt-getclean commented 5 years ago

Hi We are using kbfsfuse to store secrete during a ci-pipeline. This works mostly excellent so thanx for the great stuff However sometimes we write stuff and than the last secret stored is likely to get lost since the process is killed before kbfs has the time to complete the update. I have the basic feeling that keybase ctl stop should be able to help me here. I could first use this to stop the process and than keep the script alive until I have verified that the kbfs process is gone. however. keybase ctl stop does not work and ends up in a loop.

my log id: 7456cde138762f3b40a8e61c

A second note,.. even though it feel keybase ctl stop should store data before it kills kbfs when I test this with echo "my test" > /keybase/public/aaldert/test && keybase ctl stop No file is created

Again thnx for the cool stuff. Let me know if I can help with more info

sudoapt-getclean commented 5 years ago

I intended to log this under kbfsfuse offcourse

strib commented 5 years ago

Thanks for the thoughtful issue. keybase ctl stop currently has nothing to do with kbfs, they are separate processes. It is only intended to control the background keybase daemon, which manages local device identity and chat.

There's currently no built-in command to wait for kbfs to finish uploading its data, but it should be very easy to script. There's a virtual json file you can read and parse: /keybase/.kbfs_status. When JournalServer.UnflushedBytes becomes 0, then you know KBFS has finished uploading everything you've previously written to the server.

Would that address your use case?

sudoapt-getclean commented 5 years ago

wow that is magic ;-)

/keybase # ls -al /keybase/
total 0
dr-x------    1 root     root             0 Oct 16 22:11 private
dr-x------    1 root     root             0 Oct 16 22:11 public
dr-x------    1 root     root             0 Oct 16 22:11 team
/keybase # ls -al /keybase/.kbfs_status
-r--r--r--    1 root     root          4588 Aug 30  1754 /keybase/.kbfs_status

it sounds like something like this should work, but for my initial test it doesn't

while [ $( cat /keybase/.kbfs_status | jq .JournalServer.UnflushedBytes ) != 0 ];
do
    echo "==> wait for flush"
done

further more as far as I can see unflushedbytes never goes up not even in a test like

echo "test test" > /keybase/team/aaaaaaaa/asd && while true;
> do
> cat /keybase/.kbfs_status | jq .JournalServer.UnflushedBytes
> done
0
0
0
0
0
0

Does it by any chance matter that I'm writing to a team volume?

Something I don't understand

keybase ctl stop currently has nothing to do with kbfs

this suprises me cause it does cause this to show up in the kbfs logs [WARN kbfs keybase_daemon_rpc.go:444] 325 NotifyService: Shutdown and than the kbfs proces goes away,

strib commented 5 years ago

0 is a good thing, it means it flushed very quickly! Try something like this:

$ dd if=/dev/urandom of=/tmp/1mb bs=1024 count=1024
$ cp /tmp/1mb /keybase/team/aaaaaaaa/asd && while true; do cat /keybase/.kbfs_status | jq .JournalServer.UnflushedBytes; done
0
0
1057825
9131
0
0
0
0
0

this suprises me cause it does cause this to show up in the kbfs logs [WARN kbfs keybase_daemon_rpc.go:444] 325 NotifyService: Shutdown and than the kbfs proces goes away,

It surprises me that kbfs would go away on a non-Windows machine (assuming from your commands that you're not on Windows), since the code is pretty explicit about it:

https://github.com/keybase/kbfs/blob/21de2e51dbb2007dc20fe996008cf27b6720c8dd/libkbfs/keybase_daemon_rpc.go#L443-L449

strib commented 5 years ago

Well actually I guess those initial 0s are a problem, since KBFS buffers data for up to a second in memory before it starts flushing them. So you can either hardcode a 1-second wait, or do something like:

$ dd if=/dev/urandom of=/tmp/1mb bs=1024 count=1024
$ cp /tmp/1mb /keybase/team/aaaaaaaa/asd && while true; do cat /keybase/team/aaaaaaaa/.kbfs_status | jq .Journal.UnflushedBytes,.DirtyPaths; done
0
[
  "aaaaaaaa/test"
]
0
[
  "aaaaaaaa/test"
]
0
[
  "aaaaaaaa/test"
]
0
[
  "aaaaaaaa/test"
]
8875
[
  "aaaaaaaa/test"
]
0
null
0
null

And check both for a null list and 0 bytes unflushed. (Note the kbfs_status file is now inside the folder, rather than right at /keybase.)

strib commented 5 years ago

Also, on Linux, ctl stop doesn't stop kbfsfuse for me:

$ ps auwwx | grep kbfsfuse
strib    13052  0.0  0.0  14224   984 pts/21   S+   16:25   0:00 grep --color=auto kbfsfuse
strib    24769  0.1  0.3 900584 124636 ?       Ssl  08:58   0:34 /usr/bin/kbfsfuse -debug -log-to-file
$ keybase ctl stop
$ ps auwwx | grep kbfsfuse
strib    13068  0.0  0.0  14224  1084 pts/21   S+   16:25   0:00 grep --color=auto kbfsfuse
strib    24769  0.1  0.3 900584 124636 ?       Ssl  08:58   0:34 /usr/bin/kbfsfuse -debug -log-to-file
$ ps auwwx | grep kbfsfuse
strib    13072  0.0  0.0  14224  1088 pts/21   S+   16:25   0:00 grep --color=auto kbfsfuse
strib    24769  0.1  0.3 900584 124636 ?       Ssl  08:58   0:34 /usr/bin/kbfsfuse -debug -log-to-file
sudoapt-getclean commented 5 years ago

Thanx for your examples they helped a lot and you went above and beyond the call of duty! I didn't realise every kbfs directory has a different .kbfs_status file.

From my initial testing this script looks like it's doing the job. (I put it here also as a reference for people who find this with google)

#!/usr/bin/env bash

KBD=$1

if [ -z "${KBD}" ]; then
    echo "==# wait_for_flush should be called with the path to the directory where you wrote the last file."
    exit 1
fi

while [ $( cat "${KBD}"/.kbfs_status | jq '.DirtyPaths == null' ) == "false" ];
do
    echo "==> Wait for flush"
    sleep 1
done

I'm not explicitly checking the UnflushedBytes since as far as I can see they are always zero when dirty paths is empty.

This is how ctl stop looks for me, I'm on MacOS High Sierra

bash-3.2$ ps auwwx | grep kbfs
aaldertvanwijk   94160   0.0  0.0  4276544    956 s009  R+   10:12AM   0:00.00 grep kbfs
aaldertvanwijk   94136   0.0  1.6 558501628 264084   ??  S    10:11AM   0:00.57 /Applications/Keybase.app/Contents/SharedSupport/bin/kbfs -debug -log-file=/Users/aaldertvanwijk/Library/Logs/keybase.kbfs.log -runtime-dir=/Users/aaldertvanwijk/Library/Caches/Keybase /Volumes/Keybase (aaldertvanwijk)
bash-3.2$ keybase ctl stop
▶ INFO Stopping Keybase app
▶ INFO Terminated Keybase [94103]
▶ INFO Uninstall mount: /Volumes/Keybase (aaldertvanwijk)
bash-3.2$ ps auwwx | grep kbfs
aaldertvanwijk   94184   0.0  0.0  4268352    860 s009  R+   10:13AM   0:00.00 grep kbfs
bash-3.2$ keybase --version
keybase version 2.7.3-20181005191950+83f5d808a7
bash-3.2$ /Applications/Keybase.app/Contents/SharedSupport/bin/kbfs --version
1.0.2-20181005192046+fd221dc9

As you can see I have no kbfsfuse so I grep for kbfs