Speed up gpg initialization (#1528)

Fixes #1527

RELEASE_NOTES=[ENHANCEMENT] Cache gpg binary location

Signed-off-by: Dominik Schulz <[email protected]>

.gitignore

@@ -6,6 +6,9 @@ dev.sh
 coverage.out
 coverage-all.*
 
+# Profiling
+*.out
+
 # Compiled Object files, Static and Dynamic libs (Shared Objects)
 *.o
 *.a

internal/backend/crypto/gpg/cli/binary.go

@@ -3,10 +3,15 @@ package cli
 import (
 	"context"
 	"errors"
+	"fmt"
+	"io/ioutil"
 	"os/exec"
+	"path/filepath"
 	"sort"
+	"strings"
 
 	"github.com/gopasspw/gopass/internal/debug"
+	"github.com/gopasspw/gopass/pkg/appdir"
 )
 
 var (
@@ -21,25 +26,51 @@ func (g *GPG) Binary() string {
 	return g.binary
 }
 
+func binaryLocCacheFn() string {
+	return filepath.Join(appdir.UserCache(), "gpg-binary.loc")
+}
+
+func readBinaryLocFromCache() (string, error) {
+	fn := binaryLocCacheFn()
+	buf, err := ioutil.ReadFile(fn)
+	if err != nil {
+		return "", err
+	}
+	loc := strings.TrimSpace(string(buf))
+	if loc == "" {
+		return "", fmt.Errorf("empty location in cache")
+	}
+	return loc, nil
+}
+
+func writeBinaryLocToCache(fn string) error {
+	return ioutil.WriteFile(binaryLocCacheFn(), []byte(fn), 0644)
+}
+
 // Binary returns the GPG binary location
 func Binary(ctx context.Context, bin string) (string, error) {
 	if gpgBinC != "" {
 		return gpgBinC, nil
 	}
+	if binLoc, err := readBinaryLocFromCache(); err == nil {
+		gpgBinC = binLoc
+		debug.Log("read binary from cache: %s", binLoc)
+		return binLoc, nil
+	}
 
 	bins, err := detectBinaryCandidates(bin)
 	if err != nil {
 		return "", err
 	}
 	bv := make(byVersion, 0, len(bins))
 	for _, b := range bins {
-		debug.Log("gpg.detectBinary - Looking for '%s' ...", b)
+		debug.Log("Looking for '%s' ...", b)
 		if p, err := exec.LookPath(b); err == nil {
 			gb := gpgBin{
 				path: p,
 				ver:  version(ctx, p),
 			}
-			debug.Log("gpg.detectBinary - Found '%s' at '%s' (%s)", b, p, gb.ver.String())
+			debug.Log("Found '%s' at '%s' (%s)", b, p, gb.ver.String())
 			bv = append(bv, gb)
 		}
 	}
@@ -48,7 +79,10 @@ func Binary(ctx context.Context, bin string) (string, error) {
 	}
 	sort.Sort(bv)
 	binary := bv[len(bv)-1].path
-	debug.Log("gpg.detectBinary - using '%s'", binary)
+	debug.Log("using '%s'", binary)
 	gpgBinC = binary
+	if err := writeBinaryLocToCache(binary); err != nil {
+		debug.Log("failed to write binary location to cache file: %s", err)
+	}
 	return binary, nil
 }

main.go

@@ -8,6 +8,7 @@ import (
 	"os"
 	"os/signal"
 	"runtime"
+	"runtime/pprof"
 	"sort"
 	"strings"
 	"time"
@@ -49,6 +50,17 @@ var (
 )
 
 func main() {
+	if cp := os.Getenv("GOPASS_CPU_PROFILE"); cp != "" {
+		f, err := os.Create(cp)
+		if err != nil {
+			log.Fatalf("could not create CPU profile at %s: %s", cp, err)
+		}
+		defer f.Close()
+		if err := pprof.StartCPUProfile(f); err != nil {
+			log.Fatalf("could not start CPU profile: %s", err)
+		}
+		defer pprof.StopCPUProfile()
+	}
 	if err := protect.Pledge("stdio rpath wpath cpath tty proc exec"); err != nil {
 		panic(err)
 	}
@@ -83,6 +95,17 @@ func main() {
 		log.Fatal(err)
 	}
 	q.Wait(ctx)
+	if mp := os.Getenv("GOPASS_MEM_PROFILE"); mp != "" {
+		f, err := os.Create(mp)
+		if err != nil {
+			log.Fatalf("could not write mem profile to %s: %s", mp, err)
+		}
+		defer f.Close()
+		runtime.GC()
+		if err := pprof.WriteHeapProfile(f); err != nil {
+			log.Fatalf("could not write heap profile: %s", err)
+		}
+	}
 }
 
 func setupApp(ctx context.Context, sv semver.Version) (context.Context, *cli.App) {

pkg/fsutil/fsutil.go

@@ -61,7 +61,7 @@ func IsFile(path string) bool {
 			// not found
 			return false
 		}
-		debug.Log("failed to check dir %s: %s\n", path, err)
+		debug.Log("failed to check file %s: %s\n", path, err)
 		return false
 	}