gopass show incredibly slow

[mifrandir]

Summary

The gopass show command takes a very long time.

This applies to the time it takes to find the entry (i.e. how long it takes to print Found exact match in...), to the time it takes to decrypt the entry (i.e. delay before asking for password and delay before copying to clipboard) and to the time it takes to stop the program (i.e. delay before the shell becomes responsive again).

However, this seems to only apply to the show command. Others, like list and even find work fine.

Steps To Reproduce

I do not know how to reproduce.

Expected behavior

The command should be fast.

Environment

• OS: Arch Linux
• OS version: Linux arch 5.8.5-zen1-1-zen #1 ZEN SMP PREEMPT Thu, 27 Aug 2020 18:52:58 +0000 x86_64 GNU/Linux
• gopass Version:

gopass 1.10.1 (2020-08-25 21:48:36) go1.15 linux amd64
<root>     - gpg 2.2.21 - git 2.28.0
Available Crypto Backends: age, gpgcli, plain
Available Storage Backends: fs, gitfs, ondisk

• Installation method: pacman

Additional context

Running under KDE Plasma 5 using bspwm.

[mifrandir]

It appears that this only applies to the gopass show -c command.

[dominikschulz]

Interesting. Thanks for reporting. I haven't noticed such behaviour myself - but I rarely use the copy flag.
I wonder what's going on because decryption always happens before copying to clipboard (obviously).

[dominikschulz]

You might want to run with GOPASS_DEBUG_LOG=/tmp/gopass.log gopass show -c entry to see if you can spot where the time is spent in the log. If that doesn't help you feel free to post the log here. But please make sure to redact any confidential information from the log.

[AnomalRoil]

Maybe we should try and setup a benchmarking CI check for the standard operations, it should be fairly easily using Go built-in go test -bench to be able to detect significant slow down. (Although our external dependency on gpg and git make it a bit harder to have a good idea of what "normal speed" might mean for the CI.)

[dominikschulz]

Hmm, not sure I can follow.

Would you propose to add micro benchmarks for any CLI subcommand? Not sure how that would work. But happy to consider a PR if you send one.

[AnomalRoil]

Yeah, I'll try to create a couple benchmarks in the coming month :)

[BoostCookie]

There is quite a big difference between pass and gopass, when copying to the clipboard:

% time pass -c forum.artixlinux.org
Copied forum.artixlinux.org to clipboard. Will clear in 45 seconds.
pass -c forum.artixlinux.org  0,04s user 0,03s system 52% cpu 0,130 total
% time gopass -c forum.artixlinux.org
✔ Copied forum.artixlinux.org to clipboard. Will clear in 45 seconds.
gopass -c forum.artixlinux.org  1,94s user 0,55s system 295% cpu 0,845 tota

0.13 s with pass vs. 0.85 s with gopass!

[BoostCookie]

You might want to run with GOPASS_DEBUG_LOG=/tmp/gopass.log gopass show -c entry to see if you can spot where the time is spent in the log.

I did exactly that (and added a few more debug flags), and the longest time is spent on this if-statement:

gopass/pkg/clipboard/clipboard.go

Line 51 in 4ff8832

if err := clear(ctx, name, content, timeout); err != nil {

EDIT:
To be even more exact this is the offending line:

gopass/pkg/clipboard/clipboard_others.go

Line 24 in 4ff8832

hash, err := argon2id.Generate(string(content), 0)

Can someone please explain why this is done in the first place? Why do we clear the clipboard before writing the password to it? Why do need to hash something? What is going on here? Who am I?

EDIT2:
git-blame points towards 6d86b63.
It claims to have solved #1816.

[dominikschulz]

@BoostCookie clear is launching another instance of gopass in the background. It will wait for the specified timeout and then erase the clipboard - but only if the content (hash) matches what we wrote. We don't want to mess with the content otherwise.