@rahul2393 here, I am adding a test file in a few, cleaning up a bit

@yordis can you fix go vet issues?

@rahul2393 working on making CI to pass, yes

It is 3AM, so I am going to sleep, I will come back to this around 11 AM EST

@yordis TestSpannerTracesWithOpenTelemetry is now failing means trace status shows error which was fixed by calling the last Recv in go routine.

Calling last Recv in go routine was indeed to fix that #12235

With the PR changes I again started to see error status in traces, which was fixed earlier in 1.81.1

@yordis Can you share what does the trace look like at your end in case of context cancelled error, for me in mainline code status is always unset in traces, does it happen for all ExecuteStreamingSQL traces or just few at random?

I dont see anything weird, it will help a ton to get #12631 so I can have better data (well, the downside I can not upgrade 😭)

@yordis Is it possible for you to test this patch and see if context cancel still happens

go mod edit -replace cloud.google.com/go/spanner=github.com/googleapis/google-cloud-go/spanner@fix-issue-12630
go mod tidy
go mod download

TestSpannerTracesWithOpenTelemetry

Just run this test on your local and check if it passes.

does it happen for all ExecuteStreamingSQL traces or just few at random?

Random, but it could be the case for the same query. What do you have in mind? Picking your brain will help me to understand what to look for

I think context cancel is happening because of this #11854 (comment), we should not cancel in iter.Stop if it's already planned to be cancelled in separate go routine in case of skipping trailers.

we should not cancel in iter.Stop if it's already planned to be cancelled in separate go routine in case of skipping trailers.

That make sense to me. What do you think the route should be here? I do not feel qualify to understand the entire situation at this point. I am just trying to be proactive, but I rather not be a distraction or slowness here

Is there a way for you to verify in your test environment this patch

go mod edit -replace cloud.google.com/go/spanner=github.com/googleapis/google-cloud-go/spanner@fix-issue-12630
go mod tidy
go mod download

and confirm issue is not happening, if yes then I can include the change in next release

@yordis Another case is when application does not iterate over all the rows and call iter.Stop, then context cancel will appear in traces, and that's a valid case.

Are we sure we are not skipping rows? example code which can cause "context cancel" issue is below.

// sql query will return 4 rows
iter := client.Single().Query(context.Background(), spanner.NewStatement(sql))
// By calling Stop() after consuming only one row, we guarantee that the
// iterator's cancel function is still active. This will cancel the
// underlying stream while the background goroutine is waiting for the
// delayed trailer, thus reliably reproducing the race condition.
_, err := iter.Next()
if err != nil && err != iterator.Done {
t.Fatalf("iter.Next() failed unexpectedly: %v", err)
}
iter.Stop()

Above code is wrong since we called iter.Stop without iterating over all the rows
OR, if we pass context with a deadline and it takes more time to process the result.

// Example with Timeout
ctx, cancel := context.WithTimeout(context.Background(), 500*time.Millisecond)
defer cancel()

iter := client.Single().Query(ctx, ...) // Pass the cancellable context
// If the iter.Do() takes longer than 500ms, the context will be canceled.
err := iter.Do(func(r *spanner.Row) error {
    time.Sleep(1 * time.Second) // Simulate long processing
    return nil
})
// err will be context.DeadlineExceeded, which is a form of cancellation.

Another case is when application does not iterate over all the rows and call iter.Stop, then context cancel will appear in traces, and that's a valid case.

Let me dig into this, I feel this is the case!

In 1.80, did you fix reporting to the OTEL, correct?

I want to confirm because before we did not have any error in the trace, but now we do, so it could be the case that the app was "broken" before, and we are chasing ghosts here.

In 1.81.1 we fixed the reporting of error in traces, specifically this commit #12235

Well, I was using 1.83.0, so could be the case that wasn't fixed properly?

And what I mean by "fix" is that, I wouldn't see a "failure" in my trace. Otherwise we would have "error" signalling when it is expected behavior

Well, I was using 1.83.0, so could be the case that wasn't fixed properly?

It is fixed in 1.81.1 and I am not able to see context cancel errors for valid cases, but if we try to do this #12630 (comment) then it will happen in traces and that's valid case, one should not call iter.Stop without iterating over all the rows.

Can you write a test replicate the context cancel span behaviour using the public methods available? I am not able to replicate your case.

Let me report back, I think that we actually have a "bug" in our end, and we dont need to fix anything here.

application does not iterate over all the rows and call iter.Stop,

What if I don't want to iterate over the whole list and we do not want to see an issue?

Disclaimer, we are using https://github.com/googleapis/go-gorm-spanner so we aren't calling iter.Stop() or dealing with the situation at all,

Here is the one that is actually failing:

func apiCall(ctx context.Context, db *gorm.DB, shopSellerId uuid.UUID) (uuid.UUID, error) {
	var shopSeller models.ShopSeller
	err := db.WithContext(ctx).
		Where("id = ? AND deleted_at IS NULL", shopSellerId).
		First(&shopSeller).Error

	if err != nil {
		if errors.Is(err, gorm.ErrRecordNotFound) {
			return uuid.Nil, fmt.Errorf("...", ErrShopSellerResolutionFailed, shopSellerId)
		}
		return uuid.Nil, fmt.Errorf("...", err)
	}

	shopId, err := uuid.Parse(shopSeller.ShopID)
	if err != nil {
		return uuid.Nil, fmt.Errorf("...", err)
	}

	return shopId, nil
}

The interesting thing is that, I am unsure why Gorm would decide to use "streaming" version for this query; I dont understand Spanner, but it feels streaming would be for long-running queries, or something that wouldn't be selecting a single row

Could be we need https://github.com/googleapis/go-gorm-spanner/releases/tag/v1.8.1 (the weird thing is that I can not see file changes from the PR ...)

There is no file changes because it just update the spanner dependency and dummy PR was to run the release process there, let me dig into GORM now since so far I was just looking into spanner client, what version of GORM spanner are you using?

I just tested in latest everything just in case

cloud.google.com/go/spanner v1.83.0
github.com/googleapis/go-gorm-spanner v1.8.2

So I am gonna test my actual branch by now ... sorry, just trying to gather more data just in case

btw @rahul2393 would be better to jump into a Google Meet? Your team should have our contact info if I am not mistaken

With the following change:

replace cloud.google.com/go/spanner => github.com/googleapis/google-cloud-go/spanner v1.83.1-0.20250801175611-daf851f83e36

The issue didn't go away 100% they are few calls still, but notice the drop on that particular report

@rpc.method:ExecuteStreamingSql @error.message:"context canceled" 

Since I do not have #12631 it is really difficult to see what queries are those; but the fact that it is the very last one, makes me think the issue still present

The issue didn't go away 100% they are few calls still, but notice the drop on that particular report

I assume you wanted to attach before and after report, but there is only one report is it before?

I assume you wanted to attach before and after report, but there is only one report is it before?

See the drop in the graph

@yordis I was able to replicate and track what's happening
I added this patch add-gcp-attribute-traces...add-gcp-attribute-traces-patch to log sequence of events for stream close in mainline

In case of context cancel error

In case of success

So what should be the resolution here based on your understanding thus far?

@yordis
Can you try this patch and see if you still see context cancelled errors

go mod edit -replace cloud.google.com/go/spanner=github.com/googleapis/google-cloud-go/spanner@fix-issue-12630
go mod tidy
go mod download

Closing in favor of #12635