kimono-koans / httm

Interactive, file-level Time Machine-like tool for ZFS/btrfs/nilfs2 (and even Time Machine and Restic backups!)
https://crates.io/crates/httm
Mozilla Public License 2.0
1.38k stars 29 forks source link

--preview does not work #90

Closed magnetophon closed 1 year ago

magnetophon commented 1 year ago

Describe the bug I am not getting any previews. My symptoms are very similar to https://github.com/kimono-koans/httm/issues/57, so maybe I should have re-opened that one, but because it is quite old I decided not to. Feel free to correct me on that.

When I run httm --preview -s, I get: image When I select test.txt, I get: image

I'm running 0.30.4, from https://github.com/NixOS/nixpkgs/pull/267886.

As discussed in https://github.com/kimono-koans/httm/issues/88, the scripts are in my $PATH. I have tried in fish and bash, both as root and as user.

I tried to run execsnoop-bpfcc -x -q, but that binary doesn't exist in the package you linked to in the other issue.

la /nix/store/wijbi86ajq7kqs3vf3901ch9wydjyhhb-bpftrace-0.19.1/bin/
Permissions Links Size User Group Date Modified    Name                  Permissions Links Size User Group Date Modified    Name              Permissions Links Size User Group Date Modified    Name
lrwxrwxrwx      2    - root root  1970-01-01 01:00 bashreadline.bt@      lrwxrwxrwx      2    - root root  1970-01-01 01:00 loads.bt@         lrwxrwxrwx      2    - root root  1970-01-01 01:00 syscount.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 biolatency-kp.bt@     lrwxrwxrwx      2    - root root  1970-01-01 01:00 mdflush.bt@       lrwxrwxrwx      2    - root root  1970-01-01 01:00 tcpaccept.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 biolatency.bt@        lrwxrwxrwx      2    - root root  1970-01-01 01:00 naptime.bt@       lrwxrwxrwx      2    - root root  1970-01-01 01:00 tcpconnect.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 biosnoop.bt@          lrwxrwxrwx      2    - root root  1970-01-01 01:00 oomkill.bt@       lrwxrwxrwx      2    - root root  1970-01-01 01:00 tcpdrop.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 biostacks.bt@         lrwxrwxrwx      2    - root root  1970-01-01 01:00 opensnoop.bt@     lrwxrwxrwx      2    - root root  1970-01-01 01:00 tcplife.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 bitesize.bt@          lrwxrwxrwx      2    - root root  1970-01-01 01:00 pidpersec.bt@     lrwxrwxrwx      2    - root root  1970-01-01 01:00 tcpretrans.bt@
.r-xr-xr-x      2 3.0M root root  1970-01-01 01:00 bpftrace*             lrwxrwxrwx      2    - root root  1970-01-01 01:00 runqlat.bt@       lrwxrwxrwx      2    - root root  1970-01-01 01:00 tcpsynbl.bt@
.r-xr-xr-x      2 1.6M root root  1970-01-01 01:00 bpftrace-aotrt*       lrwxrwxrwx      2    - root root  1970-01-01 01:00 runqlen.bt@       lrwxrwxrwx      2    - root root  1970-01-01 01:00 threadsnoop.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 capable.bt@           lrwxrwxrwx      2    - root root  1970-01-01 01:00 setuids.bt@       lrwxrwxrwx      2    - root root  1970-01-01 01:00 undump.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 cpuwalk.bt@           lrwxrwxrwx      2    - root root  1970-01-01 01:00 ssllatency.bt@    lrwxrwxrwx      2    - root root  1970-01-01 01:00 vfscount.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 dcsnoop.bt@           lrwxrwxrwx      2    - root root  1970-01-01 01:00 sslsnoop.bt@      lrwxrwxrwx      2    - root root  1970-01-01 01:00 vfsstat.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 execsnoop.bt@         lrwxrwxrwx      2    - root root  1970-01-01 01:00 statsnoop.bt@     lrwxrwxrwx      2    - root root  1970-01-01 01:00 writeback.bt@
lrwxrwxrwx      2    - root root  1970-01-01 01:00 gethostlatency.bt@    lrwxrwxrwx      2    - root root  1970-01-01 01:00 swapin.bt@        lrwxrwxrwx      2    - root root  1970-01-01 01:00 xfsdist.bt@

So I tried execsnoop.bt -x -q:

/nix/store/wijbi86ajq7kqs3vf3901ch9wydjyhhb-bpftrace-0.19.1/bin/bpftrace: invalid option -- 'x'
USAGE:
    bpftrace [options] filename
    bpftrace [options] - <stdin input>
    bpftrace [options] -e 'program'

OPTIONS:
    -B MODE        output buffering mode ('full', 'none')
    -f FORMAT      output format ('text', 'json')
    -o file        redirect bpftrace output to file
    -e 'program'   execute this program
    -h, --help     show this help message
    -I DIR         add the directory to the include search path
    --include FILE add an #include file before preprocessing
    -l [search]    list probes
    -p PID         enable USDT probes on PID
    -c 'CMD'       run CMD and enable USDT probes on resulting process
    --usdt-file-activation
                   activate usdt semaphores based on file path
    --unsafe       allow unsafe builtin functions
    -q             keep messages quiet
    --info         Print information about kernel BPF support
    -k             emit a warning when a bpf helper returns an error (except read functions)
    -kk            check all bpf helper functions
    -V, --version  bpftrace version
    --no-warnings  disable all warning messages

TROUBLESHOOTING OPTIONS:
    -v                      verbose messages
    -vv                     more verbose messages (max 2)
    -d                      (dry run) debug info
    -dd                     (dry run) verbose debug info
    --emit-elf FILE         (dry run) generate ELF file with bpf programs and write to FILE
    --emit-llvm FILE        write LLVM IR to FILE.original.ll and FILE.optimized.ll

ENVIRONMENT:
    BPFTRACE_STRLEN             [default: 64] bytes on BPF stack per str()
    BPFTRACE_NO_CPP_DEMANGLE    [default: 0] disable C++ symbol demangling
    BPFTRACE_MAP_KEYS_MAX       [default: 4096] max keys in a map
    BPFTRACE_CAT_BYTES_MAX      [default: 10k] maximum bytes read by cat builtin
    BPFTRACE_MAX_PROBES         [default: 512] max number of probes
    BPFTRACE_MAX_BPF_PROGS      [default: 512] max number of generated BPF programs
    BPFTRACE_LOG_SIZE           [default: 1000000] log size in bytes
    BPFTRACE_PERF_RB_PAGES      [default: 64] pages per CPU to allocate for ring buffer
    BPFTRACE_NO_USER_SYMBOLS    [default: 0] disable user symbol resolution
    BPFTRACE_CACHE_USER_SYMBOLS [default: auto] enable user symbol cache
    BPFTRACE_VMLINUX            [default: none] vmlinux path used for kernel symbol resolution
    BPFTRACE_BTF                [default: none] BTF file
    BPFTRACE_STR_TRUNC_TRAILER  [default: '..'] string truncation trailer
    BPFTRACE_STACK_MODE         [default: bpftrace] Output format for ustack and kstack builtins

EXAMPLES:
bpftrace -l '*sleep*'
    list probes containing "sleep"
bpftrace -e 'kprobe:do_nanosleep { printf("PID %d sleeping...\n", pid); }'
    trace processes calling sleep
bpftrace -e 'tracepoint:raw_syscalls:sys_enter { @[comm] = count(); }'
    count syscalls by process name

When I run execsnoop.bt -q I get a seemingly unending stream of output:

TIME(ms)   PID   ARGS
689        625441 /run/current-system/sw/bin/fish -c  sudo /root/.local/bin/get_fan_rpm.sh
698        625443 /nix/store/9c5qm297qnvwcf7j0gm01qrslbiqz8rs-gnused-4.9/bin/sed s/[ \t]//g
700        625444 /nix/store/q1c2flcykgr4wwg5a6h450hxbk4ch589-bash-5.2-p15/bin/bash -c env
702        625444 env
703        625445 /nix/store/q1c2flcykgr4wwg5a6h450hxbk4ch589-bash-5.2-p15/bin/bash -c source /etc/fish/foreign-env/shellInit && echo && echo '---DIVIDER---' && env
705        625445 env
714        625446 sudo /root/.local/bin/get_fan_rpm.sh
714        625446 sudo /root/.local/bin/get_fan_rpm.sh
724        625447 /root/.local/bin/get_fan_rpm.sh
724        625447 bash /root/.local/bin/get_fan_rpm.sh
724        625447 bash /root/.local/bin/get_fan_rpm.sh
724        625447 bash /root/.local/bin/get_fan_rpm.sh
724        625447 bash /root/.local/bin/get_fan_rpm.sh
725        625447 bash /root/.local/bin/get_fan_rpm.sh
725        625447 bash /root/.local/bin/get_fan_rpm.sh
725        625447 bash /root/.local/bin/get_fan_rpm.sh
725        625447 bash /root/.local/bin/get_fan_rpm.sh
725        625447 bash /root/.local/bin/get_fan_rpm.sh
725        625447 bash /root/.local/bin/get_fan_rpm.sh
727        625448 ectool pwmgetfanrpm 0
727        625449 grep -Eo [[:digit:]]+
727        625450 sed -n 2p
1689       625452 /run/current-system/sw/bin/fish -c  sudo /root/.local/bin/get_fan_rpm.sh
1698       625454 /nix/store/9c5qm297qnvwcf7j0gm01qrslbiqz8rs-gnused-4.9/bin/sed s/[ \t]//g
1700       625455 /nix/store/q1c2flcykgr4wwg5a6h450hxbk4ch589-bash-5.2-p15/bin/bash -c env
1702       625455 env

Additional context

kimono-koans commented 1 year ago

Appreciate you filing this bug report.

First things first:

As discussed in https://github.com/kimono-koans/httm/issues/88, the scripts are in my $PATH.

bowie is the script you need for the default preview. It depends on httm and diff as well. What is the output when invoked directly, like bowie /var/log/syslog? What is the output of command -v for each of these utilities?

Have you tried --preview with a custom command? Like so: httm --preview="cat {snap_file}" -s /var/log/syslog

I tried to run execsnoop-bpfcc -x -q, but that binary doesn't exist in the package you linked to in the other issue.

My guess is that the command is failing somewhere when it is passed off to be executed, so it's important to know whether the command is executed or not. This is why the -x flag in execsnoop-bpfcc -x -q is so important. It shows even failed executions. If you can find another way to show whether the command failed or not that would be very helpful.

The bug AFAICT is not knowing more, not printing an error somewhere, so I will try to create a branch of two_percent which prints an error when the output is empty like it is here, etc. See: https://github.com/kimono-koans/two_percent/commit/c2f7d47b3aa7eba75e21f27b64bf487ed19d9c57 But beyond that, it would be hard to continue with the information I have now because it seems more likely that not this is either a bug in a user created package, or some sort of Nix weirdness.

Again -- the Nix environment is very interesting, but it is not particularly interesting to me, so if we are to debug this, I would need your assurance in making sure everything, even rudimentary things, are working well on your end. It could also be a security feature re: Nix? The environment may not let you execute arbitrary shell commands within your main execution context.

magnetophon commented 1 year ago

Thanks for the quick reply!

bowie ~/test.txt
/home/bart/test.txt
__
Files /home/.zfs/snapshot/zfs-auto-snap_hourly-2023-11-20-15h00/bart/test.txt and /home/bart/test.txt differ
1c1
<       14:54
---
>       15:02

Works nicely, including colors and everything.

command -v bowie
/home/bart/.nix-profile/bin/bowie

command -v httm
/home/bart/.nix-profile/bin/httm

command -v diff
/run/current-system/sw/bin/diff

Seems fine too, AFAICT.

httm --preview="cat {snap_file}" -s ~/test.txt also doesn't give any preview.

If you can find another way to show whether the command failed or not that would be very helpful.

Sorry, IDK. I'm not even sure which command you mean.
httm doesn't fail, according to my fish prompt, but I'm guessing that's not what you mean. Or do you mean the preview command? No idea how to test that.

I would need your assurance in making sure everything, even rudimentary things, are working well on your end.

Not sure what you mean by that. Anything in particular you would like me to test?

kimono-koans commented 1 year ago

Sorry, IDK. I'm not even sure which command you mean.

In order to display a preview, the fuzzy finder requires a shell command to execute. bowie is the default shell command. Before it executes any command, httm must do some parsing of the input via the shell:

─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
Fri Oct 28 08:30:22 2022  178 bytes  "/home/kimono/.zfs/snapshot/snap_pre_2023-04-02-13:23:41_httmSnapRestore/.zshenv"
Tue May 30 13:27:26 2023  222 bytes  "/home/kimono/.zfs/snapshot/autosnap_2023-06-01_00:00:46_monthly/.zshenv"
Sun Jun 04 12:14:44 2023  220 bytes  "/home/kimono/.zfs/snapshot/autosnap_2023-09-01_00:00:52_monthly/.zshenv"
Sun Nov 12 01:34:47 2023  221 bytes  "/home/kimono/.zfs/snapshot/snap_2023-11-13-12:14:24_prepApt/.zshenv"
Sat Nov 18 14:39:11 2023  221 bytes  "/home/kimono/.zfs/snapshot/snap_2023-11-18-15:51:57_ounceSnapFileMount/.zshenv"
─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
Sat Nov 18 14:39:11 2023  221 bytes  "/home/kimono/.zshenv"
─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────

Your shell must be able to parse the above using a shell command that looks something like this:

snap_file="`echo $line | cut -d'"' -f2`"

if test -f "$snap_file" || test -d "$snap_file" || test -L "$snap_file"; then 
    exec 0<&- 
    $command 2>&1
else 
    printf "A required parameter 'snap_file' is not found or is invalid."
fi

The question is -- how does your shell handle such commands?

Not sure what you mean by that. Anything in particular you would like me to test?

I mean -- I'm not even sure what to test given your non-standard environment. I'll add features re: better specifying where --preview fails, but you may need do some of your own exploratory surgery (use some debugging tools like strace, *-bpfcc and gdb) to find out where the execution is failing in your very unique context.

I'll do a new release today and my changes should be helpful in determining where the source of the issue is, but you may need to do some experimentation on your own to root cause the issue. For instance -- testing with different preview commands.

kimono-koans commented 1 year ago

See: https://github.com/kimono-koans/httm/releases/tag/0.31.1

magnetophon commented 1 year ago

Thanks for the debug tools! Much appreciated!

When I run httm --preview -s ~/test.txt with version 0.31.2, I get: image

So the issue is that a bunch of newlines get added.

When I create a test.sh that looks like this, it works wonderfully.

snap_file="`echo 'Mon Nov 20 14:54:15 2023 6 bytes "/home/.zfs/snapshot/zfs-auto-snap_hourly-2023-11-20-15h00/bart/test.txt"' | cut -d'"' -f2`";
if test -f "$snap_file" || test -d "$snap_file" || test -L "$snap_file";
then exec 0<&-;
bowie --direct "$snap_file" "/home/bart/test.txt" 2>&1;
else printf "WARN: A";
fi
magnetophon commented 1 year ago

Out of curiosity I added some shebangs to my test script, and #!/usr/bin/env bash works, but #!/usr/bin/env fish gives:

./test.sh (line 2): Unexpected end of string, quotes are not balanced
snap_file="`echo 'Mon Nov 20 14:54:15 2023 6 bytes "/home/.zfs/snapshot/zfs-auto-snap_hourly-2023-11-20-15h00/bart/test.txt"' | cut -d'"' -f2`";
                                                                                                                                        ^
warning: Error while reading file ./test.sh

Not sure if that is relevant, cause when I run httm --preview -s ~/test.txt from bash, I get the same output as in the screenshot above, which was ran from fish.

kimono-koans commented 1 year ago

Thanks for the debug tools! Much appreciated!

When I run httm --preview -s ~/test.txt with version 0.31.2, I get: image

Your shell is adding single quotes around Mon Nov 20 14:54:15 2023 6 bytes "/home/.zfs/snapshot/zfs-auto-snap_hourly-2023-11-20-15h00/bart/test.txt" when it shouldn't.

I am almost certain this and/or some other janky sh emulation is causing this. It works on my system, but sh on my system/Ubuntu is dash. See:

ls -al `which sh`
lrwxrwxrwx. 1 root root 4 Oct 27  2022 /usr/bin/sh -> dash

You might test to confirm by using dash as your sh shell, and/or changing out your default login shell with chsh -s ....

I'll have to think about the best way to resolve because I really don't know. Your suggestions are welcome.

My inclination is simply to write the script as a bash script, and require bash to use --preview, instead of trying to work with POSIX/sh emulation.

So the issue is that a bunch of newlines get added.

Newlines replace spaces so I don't have to add a horizontal scroll feature.

magnetophon commented 1 year ago

When I change the default shell to dash, it works beautifully, so it seems the issue is fish.

magnetophon commented 1 year ago

I did some more testing. As long as the system shell is not fish, preview works fine. So I can set fish as the default program of my terminal, call httm from fish and preview still works. Ideally this should not be needed, but it's a pretty good workaround for me.

kimono-koans commented 1 year ago

I'm closing with this release: https://github.com/kimono-koans/httm/releases/tag/0.31.3

magnetophon commented 1 year ago

With that version I get just -- as a preview. :/

kimono-koans commented 1 year ago

With that version I get just -- as a preview. :/

Then -- please help me narrow it down to what the issue is! Is this re: fish or all shells? One of your shells is adding single quotes ('') around a parameter causing it to fail.

The current version bootstraps via a #!/usr/bin/env bash script, initially executed via the shell specified in your SHELL env var. See: https://github.com/kimono-koans/httm/blob/master/scripts/preview-bootstrap.bash

FYI re: 0.31.3 this works, as executed with fish, zsh and bash on my system.

IMHO this is down to something unique with the Nix environment and/or the POSIX non-compliant fish shell, which, I'll remind you, is not even close to a supported configuration. You're going to have to help me help you.

magnetophon commented 1 year ago

IMHO this is down to something unique with the Nix environment and/or the POSIX non-compliant fish shell, which, I'll remind you, is not even close to a supported configuration. You're going to have to help me help you.

Totally agreed, sorry for the vague report.

I did some more investigating. As far as I can tell the results depend only on the value of $SHELL and the version of httm, it doesn't matter which shell I'm actually in when I call httm.

With version 0.31.2 and $SHELL set to bash, it works as expected: image

When I set $SHELL to fish, version 0.31.2, I get this: image

With version 0.31.3 and 0.31.4, $SHELL set to bash: image

With version 0.31.3, $SHELL set to fish: image

With version 0.31.4, $SHELL set to fish: image

I made sure to install the new script too:

    for script in scripts/*.bash; do
      install -Dm755 "$script" "$out/bin/$(basename "$script" .bash)"
    done

Context: https://github.com/magnetophon/nixpkgs/blob/httm_0.31.4/pkgs/tools/filesystems/httm/default.nix#L39-L41

All scripts are in my path.

kimono-koans commented 1 year ago

This is interesting:

The shebang line is only used when scripts are executed without specifying the interpreter. For functions inside fish or when executing a script with fish /path/to/script, a shebang is not required (but it doesn’t hurt!).

I'm dumbfounded. fish will not honor the shebang, and just goes along and tries to execute the script on its own. I have an idea as to how to fix, but just wow.

magnetophon commented 1 year ago

I found this interesting too.

Other shells like bash, sh, & zsh run the script with the command found using the /usr/bin/env sh.

This is, quite simply, incorrect:

magnetophon commented 1 year ago

0.31.5 Just Works™, no matter what $SHELL is set to. Thanks a lot!

Just out of curiosity: I had a look at the diff, but couldn't really tell how you fixed it. Did you read the above comment, and do you agree that fish seems to behave in the same way as other shells, with regards to shebangs?