From d9ca2e6fc784aee2e3ef00feee68e763389f1c2c Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?=
 <vroldanbet@authzed.com>
Date: Tue, 26 Mar 2024 09:58:01 +0000
Subject: [PATCH] adds trace log messages to LR

to troubleshoot potential deadlock
---
 internal/graph/checkingresourcestream.go | 7 +++++++
 internal/graph/lookupresources.go        | 3 +++
 2 files changed, 10 insertions(+)

diff --git a/internal/graph/checkingresourcestream.go b/internal/graph/checkingresourcestream.go
index eb03a30c29..b365af616b 100644
--- a/internal/graph/checkingresourcestream.go
+++ b/internal/graph/checkingresourcestream.go
@@ -3,6 +3,7 @@ package graph
 import (
 	"cmp"
 	"context"
+	log "github.com/authzed/spicedb/internal/logging"
 	"slices"
 	"sync"
 
@@ -279,21 +280,26 @@ func newCheckingResourceStream(
 // waitForPublishing waits for the publishing goroutine to complete its work, and returns the number
 // of published *reachable* resources or the error that occurred during checking or publishing.
 func (crs *checkingResourceStream) waitForPublishing() (uint64, *v1.Cursor, error) {
+
+	log.Trace().Msg("marking reachable resources completed")
 	// Mark that no new items will come in from the reachable resources stream.
 	for i := 0; i < int(crs.concurrencyLimit); i++ {
 		crs.reachableResourcesCompleted <- struct{}{}
 	}
 
 	// Wait for all existing processing to complete.
+	log.Trace().Msg("waiting for all existing processing to complete")
 	crs.processingWaitGroup.Wait()
 
 	// Run a final processing call to ensure there are no remaining items.
+	log.Trace().Msg("making sure there are no remaining items in the checking stream")
 	_, err := crs.runProcess(true)
 	if err != nil {
 		return 0, nil, err
 	}
 
 	// Mark publishing as ready for final publishing.
+	log.Trace().Msg("marking publishing as ready for final publishing")
 	select {
 	case crs.availableForPublishing <- false:
 		break
@@ -304,6 +310,7 @@ func (crs *checkingResourceStream) waitForPublishing() (uint64, *v1.Cursor, erro
 	}
 
 	// Wait for any remaining publishing to complete.
+	log.Trace().Msg("waiting for any remaining publishing to complete")
 	crs.publishingWaitGroup.Wait()
 
 	return crs.reachableResourcesCount, crs.lastReachableResourceCursor, crs.err
diff --git a/internal/graph/lookupresources.go b/internal/graph/lookupresources.go
index 3dde13e67e..1105df836b 100644
--- a/internal/graph/lookupresources.go
+++ b/internal/graph/lookupresources.go
@@ -3,6 +3,7 @@ package graph
 import (
 	"context"
 	"errors"
+	log "github.com/authzed/spicedb/internal/logging"
 
 	"github.com/authzed/spicedb/internal/dispatch"
 	"github.com/authzed/spicedb/pkg/datastore"
@@ -77,11 +78,13 @@ func (cl *CursoredLookupResources) LookupResources(
 			}
 		}
 
+		log.Trace().Msg("waiting for checking stream publishing")
 		reachableCount, newCursor, err := checkingStream.waitForPublishing()
 		if err != nil {
 			return err
 		}
 
+		log.Trace().Uint64("reachable-count", reachableCount).Msg("completed checking stream publishing")
 		reachableResourcesCursor = newCursor
 		if reachableCount == 0 {
 			return nil