diff --git a/cmd/server/main.go b/cmd/server/main.go index e110296..8f5b3a8 100644 --- a/cmd/server/main.go +++ b/cmd/server/main.go @@ -90,13 +90,10 @@ func main() { AddSource: true, Level: slog.LevelInfo, ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr { - // Shorten source paths to relative paths for cleaner logs + // Use basename for source file for cleaner logs if a.Key == slog.SourceKey { if source, ok := a.Value.Any().(*slog.Source); ok { - // Find project root by looking for /slacker/ in path - if idx := strings.LastIndex(source.File, "/slacker/"); idx >= 0 { - source.File = source.File[idx+9:] // Skip "/slacker/" - } + source.File = filepath.Base(source.File) } } return a diff --git a/pkg/bot/bot.go b/pkg/bot/bot.go index e88b986..c7c0813 100644 --- a/pkg/bot/bot.go +++ b/pkg/bot/bot.go @@ -59,19 +59,21 @@ type messageUpdateParams struct { // //nolint:govet // Field order optimized for logical grouping over memory alignment type Coordinator struct { - processingEvents sync.WaitGroup // Tracks in-flight event processing for graceful shutdown - stateStore StateStore // Persistent state across restarts - sprinklerURL string - workspaceName string // Track workspace name for better logging - slack SlackClient - github GitHubClient - configManager ConfigManager - notifier *notify.Manager - userMapper UserMapper - threadCache *cache.ThreadCache // In-memory cache for fast lookups - commitPRCache *cache.CommitPRCache // Maps commit SHAs to PR numbers for check events - eventSemaphore chan struct{} // Limits concurrent event processing (prevents overwhelming APIs) - dmLocks sync.Map // Per-user-PR locks to prevent duplicate DMs (key: "userID:prURL") + processingEvents sync.WaitGroup // Tracks in-flight event processing for graceful shutdown + stateStore StateStore // Persistent state across restarts + sprinklerURL string + workspaceName string // Track workspace name for better logging + slack SlackClient + github GitHubClient + configManager ConfigManager + notifier *notify.Manager + userMapper UserMapper + threadCache *cache.ThreadCache // In-memory cache for fast lookups + commitPRCache *cache.CommitPRCache // Maps commit SHAs to PR numbers for check events + eventSemaphore chan struct{} // Limits concurrent event processing (prevents overwhelming APIs) + dmLocks sync.Map // Per-user-PR locks to prevent duplicate DMs (key: "userID:prURL") + recentUpdateLogsMu sync.Mutex // Protects recentUpdateLogs map + recentUpdateLogs map[string]time.Time // Tracks recent "updating message" logs to prevent spam (key: "channelID:threadTS:state") } // StateStore interface for persistent state - allows dependency injection for testing. @@ -111,16 +113,17 @@ func New( stateStore StateStore, ) *Coordinator { c := &Coordinator{ - slack: slackClient, - github: githubClient, - configManager: configManager, - notifier: notifier, - userMapper: usermapping.New(slackClient.API(), githubClient.InstallationToken(ctx)), - sprinklerURL: sprinklerURL, - stateStore: stateStore, - threadCache: cache.New(), - commitPRCache: cache.NewCommitPRCache(), - eventSemaphore: make(chan struct{}, 10), // Allow 10 concurrent events per org + slack: slackClient, + github: githubClient, + configManager: configManager, + notifier: notifier, + userMapper: usermapping.New(slackClient.API(), githubClient.InstallationToken(ctx)), + sprinklerURL: sprinklerURL, + stateStore: stateStore, + threadCache: cache.New(), + commitPRCache: cache.NewCommitPRCache(), + eventSemaphore: make(chan struct{}, 10), // Allow 10 concurrent events per org + recentUpdateLogs: make(map[string]time.Time), } // Set GitHub client in config manager for this org. @@ -569,7 +572,7 @@ func (c *Coordinator) processEvent(ctx context.Context, msg SprinklerMessage) er case "check_run", "check_suite": // Check events update PR test status - handle like pull_request events if msg.PRNumber > 0 { - slog.Info("received check event for PR, refreshing state", + slog.Debug("received check event for PR, refreshing state", "owner", owner, "repo", repo, "pr", msg.PRNumber, @@ -616,7 +619,7 @@ func (c *Coordinator) handlePullRequestEventWithData(ctx context.Context, owner, ) { prNumber := event.Number - slog.Info("PR event with pre-fetched data", + slog.Debug("PR event with pre-fetched data", logFieldOwner, owner, logFieldRepo, repo, "number", prNumber, @@ -997,12 +1000,10 @@ func (c *Coordinator) processChannelsInParallel( if !exists { // First time seeing this user taggedUsers[userID] = info - } else { + } else if info.IsInAnyChannel { // User already tagged in another channel - update IsInAnyChannel if this channel has them - if info.IsInAnyChannel { - existing.IsInAnyChannel = true - taggedUsers[userID] = existing - } + existing.IsInAnyChannel = true + taggedUsers[userID] = existing } } taggedUsersMu.Unlock() @@ -1270,16 +1271,44 @@ func (c *Coordinator) updateMessageIfNeeded(ctx context.Context, params messageU return } - slog.Info("updating message - content changed", - "workspace", c.workspaceName, - logFieldPR, fmt.Sprintf(prFormatString, params.Owner, params.Repo, params.PRNumber), - "channel", params.ChannelDisplay, - "channel_id", params.ChannelID, - "thread_ts", params.ThreadTS, - "pr_state", params.PRState, - "old_state", params.OldState, - "current_message_preview", params.CurrentText[:min(100, len(params.CurrentText))], - "expected_message_preview", expectedText[:min(100, len(expectedText))]) + // Deduplicate "updating message" logs within 1 second to reduce noise from concurrent events + logKey := fmt.Sprintf("%s:%s:%s", params.ChannelID, params.ThreadTS, params.PRState) + shouldLog := true // Default to logging if map not initialized + if c.recentUpdateLogs != nil { + c.recentUpdateLogsMu.Lock() + if lastLogged, exists := c.recentUpdateLogs[logKey]; !exists || time.Since(lastLogged) > time.Second { + c.recentUpdateLogs[logKey] = time.Now() + shouldLog = true + // Clean up old entries (older than 5 seconds) to prevent memory leak + for key, timestamp := range c.recentUpdateLogs { + if time.Since(timestamp) > 5*time.Second { + delete(c.recentUpdateLogs, key) + } + } + } else { + shouldLog = false + } + c.recentUpdateLogsMu.Unlock() + } + + if shouldLog { + slog.Info("updating message - content changed", + "workspace", c.workspaceName, + logFieldPR, fmt.Sprintf(prFormatString, params.Owner, params.Repo, params.PRNumber), + "channel", params.ChannelDisplay, + "channel_id", params.ChannelID, + "thread_ts", params.ThreadTS, + "pr_state", params.PRState, + "old_state", params.OldState, + "current_message_preview", params.CurrentText[:min(100, len(params.CurrentText))], + "expected_message_preview", expectedText[:min(100, len(expectedText))]) + } else { + slog.Debug("suppressing duplicate 'updating message' log (within 1s)", + "workspace", c.workspaceName, + logFieldPR, fmt.Sprintf(prFormatString, params.Owner, params.Repo, params.PRNumber), + "channel", params.ChannelDisplay, + "pr_state", params.PRState) + } if err := c.slack.UpdateMessage(ctx, params.ChannelID, params.ThreadTS, expectedText); err != nil { slog.Error("failed to update PR message", @@ -1326,7 +1355,7 @@ func (c *Coordinator) updateMessageIfNeeded(ctx context.Context, params messageU func (c *Coordinator) handlePullRequestFromSprinkler( ctx context.Context, owner, repo string, prNumber int, sprinklerURL string, eventTimestamp time.Time, ) { - slog.Info("handling PR event from sprinkler using turnclient", + slog.Debug("handling PR event from sprinkler using turnclient", logFieldOwner, owner, logFieldRepo, repo, "pr_number", prNumber, diff --git a/pkg/bot/bot_sprinkler.go b/pkg/bot/bot_sprinkler.go index 0bf9389..7e9a15a 100644 --- a/pkg/bot/bot_sprinkler.go +++ b/pkg/bot/bot_sprinkler.go @@ -300,7 +300,7 @@ func (c *Coordinator) handleSprinklerEvent(ctx context.Context, event client.Eve return } - slog.Info("accepted event for async processing", + slog.Debug("accepted event for async processing", "organization", organization, "type", event.Type, "url", event.URL, diff --git a/pkg/bot/dm.go b/pkg/bot/dm.go index 74e84bc..98db3bb 100644 --- a/pkg/bot/dm.go +++ b/pkg/bot/dm.go @@ -346,7 +346,7 @@ func (c *Coordinator) findDMInHistory(ctx context.Context, userID, prURL string) // Returns (shouldQueue bool, sendAfter time.Time). // Channel membership is determined by caller - if channelID is non-empty, user was in at least one channel. func (c *Coordinator) shouldDelayNewDM( - ctx context.Context, + _ context.Context, userID, channelID, channelName string, owner, _ string, ) (bool, time.Time) { @@ -526,7 +526,7 @@ func (c *Coordinator) sendDMNotificationsToTaggedUsers( err := c.sendPRNotification(ctx, dmNotificationRequest{ UserID: userInfo.UserID, ChannelID: channelID, // "delay" or empty based on channel membership - ChannelName: "", // not used + ChannelName: "", // not used Owner: owner, Repo: repo, PRNumber: prNumber,