Merge branch 'po-diskcache-log-state' into 'master'

Log all diskcache state changes and stream access

See merge request gitlab-org/gitaly!1682

3 files changed, 24 insertions, 5 deletions

diff --git a/changelogs/unreleased/po-diskcache-log-state.yml b/changelogs/unreleased/po-diskcache-log-state.yml
new file mode 100644
index 000000000..a05535d6d
--- /dev/null
+++ b/changelogs/unreleased/po-diskcache-log-state.yml
@@ -0,0 +1,5 @@
+---
+title: Log all diskcache state changes and stream access
+merge_request: 1682
+author:
+type: other
diff --git a/internal/cache/cachedb.go b/internal/cache/cachedb.go
index fc717134a..f756fa31e 100644
--- a/internal/cache/cachedb.go
+++ b/internal/cache/cachedb.go
@@ -9,6 +9,7 @@ import (
 	"sync"
 
 	"github.com/golang/protobuf/proto"
+	grpc_logrus "github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus"
 	"gitlab.com/gitlab-org/gitaly/internal/safe"
 	"gitlab.com/gitlab-org/gitaly/proto/go/gitalypb"
 )
@@ -84,6 +85,10 @@ func (sdb *StreamDB) GetStream(ctx context.Context, repo *gitalypb.Repository, r
 		return nil, err
 	}
 
+	grpc_logrus.Extract(ctx).
+		WithField("stream_path", respPath).
+		Info("getting stream")
+
 	respF, err := os.Open(respPath)
 	switch {
 	case os.IsNotExist(err):
@@ -115,6 +120,10 @@ func (sdb *StreamDB) PutStream(ctx context.Context, repo *gitalypb.Repository, r
 		return err
 	}
 
+	grpc_logrus.Extract(ctx).
+		WithField("stream_path", reqPath).
+		Info("putting stream")
+
 	var n int64
 	isWinner := sdb.af.trackFile(reqPath)
 	defer func() {
diff --git a/internal/cache/keyer.go b/internal/cache/keyer.go
index b7cc5e529..86957c3fe 100644
--- a/internal/cache/keyer.go
+++ b/internal/cache/keyer.go
@@ -13,6 +13,7 @@ import (
 
 	"github.com/golang/protobuf/proto"
 	"github.com/google/uuid"
+	grpc_logrus "github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus"
 	"gitlab.com/gitlab-org/gitaly/internal/config"
 	"gitlab.com/gitlab-org/gitaly/internal/helper"
 	"gitlab.com/gitlab-org/gitaly/internal/safe"
@@ -60,7 +61,7 @@ type lease struct {
 // EndLease will end the lease by removing the pending lease file and updating
 // the key file with the current lease ID.
 func (l lease) EndLease(ctx context.Context) error {
-	_, err := updateLatest(l.repo)
+	_, err := updateLatest(ctx, l.repo)
 	if err != nil {
 		return err
 	}
@@ -75,7 +76,7 @@ func (l lease) EndLease(ctx context.Context) error {
 	return nil
 }
 
-func updateLatest(repo *gitalypb.Repository) (string, error) {
+func updateLatest(ctx context.Context, repo *gitalypb.Repository) (string, error) {
 	repoStatePath, err := getRepoStatePath(repo)
 	if err != nil {
 		return "", err
@@ -105,6 +106,10 @@ func updateLatest(repo *gitalypb.Repository) (string, error) {
 		return "", err
 	}
 
+	grpc_logrus.Extract(ctx).
+		WithField("diskcache", nextGenID).
+		Infof("diskcache state change")
+
 	return nextGenID, nil
 }
 
@@ -164,7 +169,7 @@ func (LeaseKeyer) KeyPath(ctx context.Context, repo *gitalypb.Repository, req pr
 		return "", countErr(ErrPendingExists)
 	}
 
-	genID, err := currentGenID(repo)
+	genID, err := currentGenID(ctx, repo)
 	if err != nil {
 		return "", err
 	}
@@ -262,7 +267,7 @@ func currentLeases(repo *gitalypb.Repository) ([]os.FileInfo, error) {
 	return pendings, nil
 }
 
-func currentGenID(repo *gitalypb.Repository) (string, error) {
+func currentGenID(ctx context.Context, repo *gitalypb.Repository) (string, error) {
 	repoStatePath, err := getRepoStatePath(repo)
 	if err != nil {
 		return "", err
@@ -272,7 +277,7 @@ func currentGenID(repo *gitalypb.Repository) (string, error) {
 	switch {
 	case os.IsNotExist(err):
 		// latest file doesn't exist, so create one
-		return updateLatest(repo)
+		return updateLatest(ctx, repo)
 	case err == nil:
 		return string(latestBytes), nil
 	default: