CBG-4928: Update log messages on changes feed being cancelled #7880

RIT3shSapata · 2025-11-14T09:12:46Z

CBG-4928

Describe your PR here...

Currently SGW logs the changes feed cancellation messages at warn level with "error" in the message
These are not necessarily errors, therefore the message level and messages have been updated appropriately
The other part of this ticket is implemented in CBG-4928 do not log warning for closed blip sender #7878

Pre-review checklist

Removed debug logging (fmt.Print, log.Print, ...)
Logging sensitive data? Make sure it's tagged (e.g. base.UD(docID), base.MD(dbName))
Updated relevant information in the API specifications (such as endpoint descriptions, schemas, ...) in docs/api

Dependencies (if applicable)

Link upstream PRs
Update Go module dependencies when merged

Integration Tests

GSI=true,xattrs=true https://jenkins.sgwdev.com/job/SyncGatewayIntegration/0000/

Copilot

Pull Request Overview

This PR updates the logging approach for changes feed cancellation scenarios. Currently, these cancellations are logged as warnings with "error" in the messages, but they are not necessarily errors. The changes downgrade the log level from WarnfCtx to InfofCtx, add the base.KeyChanges log key for better filtering, and update the error messages to be more descriptive and accurate.

Key Changes

Downgraded log level from warning to info for changes feed cancellation messages
Added base.KeyChanges log key to enable targeted log filtering
Updated error messages to be more descriptive (e.g., "Error retrieving changes" → "Could not retrieve changes")

Reviewed Changes

Copilot reviewed 3 out of 3 changed files in this pull request and generated 3 comments.

File	Description
db/channel_cache_single.go	Simplified error message when changes feed is cancelled while waiting for view lock
db/changes.go	Downgraded two log statements from warning to info level and updated messages to be more descriptive
base/error.go	Updated `ErrChannelFeed` message from "Error while building channel feed" to "Failed to build channel feed"

Copilot · 2025-11-14T09:13:42Z

db/changes.go

 			changes, err := singleChannelCache.GetChanges(ctx, paginationOptions)
 			if err != nil {
-				base.WarnfCtx(ctx, "Error retrieving changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)
+				base.InfofCtx(ctx, base.KeyChanges, "Could not retrieve changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)


The error message 'Could not retrieve changes' is vague and doesn't clearly indicate that the changes feed was cancelled. Consider using a more specific message like 'Changes feed cancelled for channel %q: %v' to better reflect the actual cause.

Suggested change

base.InfofCtx(ctx, base.KeyChanges, "Could not retrieve changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)

if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) {

base.InfofCtx(ctx, base.KeyChanges, "Changes feed cancelled for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)

} else {

base.InfofCtx(ctx, base.KeyChanges, "Could not retrieve changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)

}

Copilot · 2025-11-14T09:13:42Z

db/changes.go

 							// On feed error, send the error and exit changes processing
 							if current[i].Err == base.ErrChannelFeed {
-								base.WarnfCtx(ctx, "MultiChangesFeed got error reading changes feed: %v", current[i].Err)
+								base.InfofCtx(ctx, base.KeyChanges, "Could not read changes feed: %v", current[i].Err)


The error message 'Could not read changes feed' is ambiguous and doesn't clearly indicate a cancellation scenario. Consider using 'Changes feed cancelled: %v' or 'Changes feed operation cancelled: %v' for clarity.

Suggested change

base.InfofCtx(ctx, base.KeyChanges, "Could not read changes feed: %v", current[i].Err)

base.InfofCtx(ctx, base.KeyChanges, "Changes feed cancelled: %v", current[i].Err)

Copilot · 2025-11-14T09:13:43Z

base/error.go

 	ErrUpdateCancel          = &sgError{"Cancel update"}
 	ErrImportCancelledPurged = HTTPErrorf(http.StatusNotFound, "Import Cancelled Due to Purge")
-	ErrChannelFeed           = &sgError{"Error while building channel feed"}
+	ErrChannelFeed           = &sgError{"Failed to build channel feed"}


The error message 'Failed to build channel feed' still implies a failure rather than a cancellation, which contradicts the PR's goal of treating these as non-error scenarios. Consider renaming to 'Channel feed cancelled' or similar to better reflect the intended semantics.

Suggested change

ErrChannelFeed = &sgError{"Failed to build channel feed"}

ErrChannelFeed = &sgError{"Channel feed cancelled"}

I think we can drop this, because I think this error wouldn't show up if we avoid logging it at all.

I think we cannot remove this, as its being used in multiple other places

I meant, we don't need to change the message. I think "Failure" and "Error" are roughly equivalent in severity and I think there's value to leaving the messages the same to track across releases for supportability.

It is worth changing a message if it downgrades it from an issue that customers/support has to look at, or provides additional clarity.

torcolvin · 2025-11-14T13:35:19Z

db/channel_cache_single.go

 	// overhead in that case (and prevent feedback loop on query backlog)
 	if options.ChangesCtx.Err() != nil {
-		return nil, fmt.Errorf("Changes feed cancelled while waiting for view lock")
+		return nil, fmt.Errorf("Changes feed cancelled")


Suggested change

return nil, fmt.Errorf("Changes feed cancelled")

return nil, fmt.Errorf("Changes feed cancelled %w", options.ChangesCtx.Err())

This would tell us in downstream while it was canceled, particularly if we are able to determine a cause, this will make the above easier to reason about I think.

torcolvin · 2025-11-14T13:37:28Z

db/changes.go

 			changes, err := singleChannelCache.GetChanges(ctx, paginationOptions)
 			if err != nil {
-				base.WarnfCtx(ctx, "Error retrieving changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)
+				base.InfofCtx(ctx, base.KeyChanges, "Could not retrieve changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)


Assuming the context cancellation is passed back in the error message:

if !errors.Is(err, context.Canceled) && errors.Is(err, context.DeadlineExceeded) { base.WarnfCtx(ctx, "Error retrieving changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err) }

However, I think to match the behavior of below if we don't always wrap the context error message:

Suggested change

base.InfofCtx(ctx, base.KeyChanges, "Could not retrieve changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)

if options.ChangesCtx.Err() != nil {

base.WarnfCtx(ctx, "Error retrieving changes for channel %q: %v", base.UD(singleChannelCache.ChannelID().Name), err)

}

A few tests were not being passed because the Querytimeout would just throw an error and no context will be cancelled

torcolvin · 2025-11-14T13:39:52Z

db/changes.go

 							if current[i].Err == base.ErrChannelFeed {
-								base.WarnfCtx(ctx, "MultiChangesFeed got error reading changes feed: %v", current[i].Err)


Suggested change

if current[i].Err == base.ErrChannelFeed {

base.WarnfCtx(ctx, "MultiChangesFeed got error reading changes feed: %v", current[i].Err)

if !options.ChangesCtx.Err() {

base.WarnfCtx(ctx, "MultiChangesFeed got error reading changes feed: %v", current[i].Err)

}

In this case, it's not clear whether that err from current[i].Err is better than the error returned.

torcolvin · 2025-11-14T13:47:41Z

base/error.go

 	ErrUpdateCancel          = &sgError{"Cancel update"}
 	ErrImportCancelledPurged = HTTPErrorf(http.StatusNotFound, "Import Cancelled Due to Purge")
-	ErrChannelFeed           = &sgError{"Error while building channel feed"}
+	ErrChannelFeed           = &sgError{"Failed to build channel feed"}


I think we can drop this, because I think this error wouldn't show up if we avoid logging it at all.

torcolvin · 2025-11-14T13:49:18Z

db/channel_cache_single.go

 	// Check whether the changes process has been terminated while we waited for the view lock, to avoid the view
 	// overhead in that case (and prevent feedback loop on query backlog)


Suggested change

// Check whether the changes process has been terminated while we waited for the view lock, to avoid the view

// overhead in that case (and prevent feedback loop on query backlog)

// Check whether the changes process has been terminated before running a query

torcolvin · 2025-11-20T14:43:48Z

base/error.go

 	ErrUpdateCancel          = &sgError{"Cancel update"}
 	ErrImportCancelledPurged = HTTPErrorf(http.StatusNotFound, "Import Cancelled Due to Purge")
-	ErrChannelFeed           = &sgError{"Error while building channel feed"}
+	ErrChannelFeed           = &sgError{"Failed to build channel feed"}


I meant, we don't need to change the message. I think "Failure" and "Error" are roughly equivalent in severity and I think there's value to leaving the messages the same to track across releases for supportability.

It is worth changing a message if it downgrades it from an issue that customers/support has to look at, or provides additional clarity.

torcolvin · 2025-11-20T14:44:58Z

db/changes.go

 						} else {
 							// On feed error, send the error and exit changes processing
-							if current[i].Err == base.ErrChannelFeed {
+							if options.ChangesCtx.Err() != nil {


We do want to warn when it is an error but we don't have a context cancellation.

We don't want to warn if we have a context cancellation.

torcolvin and others added 2 commits November 13, 2025 12:12

CBG-4928 do not log warning for closed blip sender

0d33616

update log messages

dd83197

RIT3shSapata requested a review from torcolvin November 14, 2025 09:12

RIT3shSapata assigned torcolvin Nov 14, 2025

Copilot AI review requested due to automatic review settings November 14, 2025 09:12

Copilot AI reviewed Nov 14, 2025

View reviewed changes

torcolvin reviewed Nov 14, 2025

View reviewed changes

torcolvin assigned RIT3shSapata and unassigned torcolvin Nov 17, 2025

torcolvin mentioned this pull request Nov 17, 2025

CBG-4928 do not log warning for closed blip sender #7878

Closed

RIT3shSapata added 2 commits November 19, 2025 17:30

fixes based on PR comments

ae24539

Merge branch 'CBG-4928-silence-close-err' into CBG-4928

51e442e

RIT3shSapata assigned torcolvin and unassigned RIT3shSapata Nov 19, 2025

RIT3shSapata requested a review from torcolvin November 19, 2025 12:01

torcolvin reviewed Nov 20, 2025

View reviewed changes

torcolvin assigned RIT3shSapata and unassigned torcolvin Nov 20, 2025

fixes based on pr comments

b028e25

RIT3shSapata requested a review from torcolvin November 21, 2025 13:42

RIT3shSapata assigned torcolvin and unassigned RIT3shSapata Nov 21, 2025

torcolvin approved these changes Nov 21, 2025

View reviewed changes

torcolvin merged commit 218470e into main Nov 21, 2025
42 checks passed

torcolvin deleted the CBG-4928 branch November 21, 2025 14:38

	base.InfofCtx(ctx, base.KeyChanges, "Could not read changes feed: %v", current[i].Err)
	base.InfofCtx(ctx, base.KeyChanges, "Changes feed cancelled: %v", current[i].Err)

	ErrChannelFeed = &sgError{"Failed to build channel feed"}
	ErrChannelFeed = &sgError{"Channel feed cancelled"}

	return nil, fmt.Errorf("Changes feed cancelled")
	return nil, fmt.Errorf("Changes feed cancelled %w", options.ChangesCtx.Err())

		if current[i].Err == base.ErrChannelFeed {
		base.WarnfCtx(ctx, "MultiChangesFeed got error reading changes feed: %v", current[i].Err)

		// Check whether the changes process has been terminated while we waited for the view lock, to avoid the view
		// overhead in that case (and prevent feedback loop on query backlog)

CBG-4928: Update log messages on changes feed being cancelled #7880

CBG-4928: Update log messages on changes feed being cancelled #7880

Uh oh!

Conversation

RIT3shSapata commented Nov 14, 2025

Pre-review checklist

Dependencies (if applicable)

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull Request Overview

Key Changes

Reviewed Changes

Uh oh!

Copilot AI Nov 14, 2025

Choose a reason for hiding this comment

Uh oh!

Copilot AI Nov 14, 2025

Choose a reason for hiding this comment

Uh oh!

Copilot AI Nov 14, 2025

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants