Skip to content

spanner: data race on mt.currOp.currAttempt #12600

Closed
#12622
Closed
spanner: data race on mt.currOp.currAttempt#12600
#12622
Assignees
rahul2393
Labels
api: spannerIssues related to the Spanner API.triage meI really want to be triaged.
@egonelbre

Description

@egonelbre
egonelbre
opened on Jul 23, 2025

Client

Spanner v1.83.0 together with github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559, although the latter is unlikely to be the cuplrit.

Environment, Code and Dependencies

It's using golang:1.24.3 image for running all tests in https://github.com/storj/storj against production Spanner.

The relevant data race warning, with application code omitted: 
WARNING: DATA RACE
Write at 0x00c008a8ddf8 by goroutine 32446:
  cloud.google.com/go/spanner.(*RowIterator).Next.func1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:178 +0x1cb
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:610 +0x5d
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:578 +0x472
  cloud.google.com/go/spanner.(*RowIterator).Next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:182 +0x4e4
  github.com/googleapis/go-sql-spanner.(*readOnlyRowIterator).Next()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/transaction.go:66 +0x35
  github.com/googleapis/go-sql-spanner.(*rows).Columns.(*rows).getColumns.func1()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:66 +0x4d
  sync.(*Once).doSlow()
      /usr/local/go/src/sync/once.go:78 +0xe1
  sync.(*Once).Do()
      /usr/local/go/src/sync/once.go:69 +0x44
  github.com/googleapis/go-sql-spanner.(*rows).getColumns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:65 +0x6e
  github.com/googleapis/go-sql-spanner.(*rows).Columns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:49 +0x25
  database/sql.(*Rows).nextLocked()
      /usr/local/go/src/database/sql/sql.go:3063 +0x15a
  database/sql.(*Rows).Next.func1()
      /usr/local/go/src/database/sql/sql.go:3041 +0x3c
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3574 +0xa6
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3040 +0x124
  // ... APPLICATION SPECIFIC CODE ...
Previous read at 0x00c008a8ddf8 by goroutine 32665:
  cloud.google.com/go/spanner.(*wrappedStream).RecvMsg()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/client.go:773 +0x30f
  cloud.google.com/go/spanner.(*wrappedStream).RecvMsg()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/client.go:750 +0x82
  cloud.google.com/go/spanner/apiv1/spannerpb.(*spannerExecuteStreamingSqlClient).Recv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/apiv1/spannerpb/spanner.pb.go:4268 +0x65
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv.func1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:681 +0x3a
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv.gowrap1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:686 +0x4f
Goroutine 32446 (running) created at:
  golang.org/x/sync/errgroup.(*Group).add()
      /go/pkg/mod/golang.org/x/sync@v0.15.0/errgroup/errgroup.go:96 +0xe4
  golang.org/x/sync/errgroup.(*Group).Go()
      /go/pkg/mod/golang.org/x/sync@v0.15.0/errgroup/errgroup.go:91 +0xb0f
  // ... APPLICATION SPECIFIC CODE ...
Goroutine 32665 (finished) created at:
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:680 +0xde4
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:676 +0x89
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:618 +0x9c8
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:578 +0x472
  cloud.google.com/go/spanner.(*RowIterator).Next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:182 +0x4e4
  github.com/googleapis/go-sql-spanner.(*readOnlyRowIterator).Next()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/transaction.go:66 +0x35
  github.com/googleapis/go-sql-spanner.(*rows).Columns.(*rows).getColumns.func1()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:66 +0x4d
  sync.(*Once).doSlow()
      /usr/local/go/src/sync/once.go:78 +0xe1
  sync.(*Once).Do()
      /usr/local/go/src/sync/once.go:69 +0x44
  github.com/googleapis/go-sql-spanner.(*rows).getColumns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:65 +0x6e
  github.com/googleapis/go-sql-spanner.(*rows).Columns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:49 +0x25
  database/sql.(*Rows).nextLocked()
      /usr/local/go/src/database/sql/sql.go:3063 +0x15a
  database/sql.(*Rows).Next.func1()
      /usr/local/go/src/database/sql/sql.go:3041 +0x3c
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3574 +0xa6
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3040 +0x124
  // ... APPLICATION SPECIFIC CODE ...
Second warning 
WARNING: DATA RACE
Write at 0x00c00aae7020 by goroutine 32665:
  cloud.google.com/go/spanner.(*wrappedStream).RecvMsg()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/client.go:759 +0x15b
  cloud.google.com/go/spanner.(*wrappedStream).RecvMsg()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/client.go:750 +0x82
  cloud.google.com/go/spanner/apiv1/spannerpb.(*spannerExecuteStreamingSqlClient).Recv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/apiv1/spannerpb/spanner.pb.go:4268 +0x65
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv.func1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:681 +0x3a
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv.gowrap1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:686 +0x4f
Previous read at 0x00c00aae7020 by goroutine 32446:
  cloud.google.com/go/spanner.(*builtinMetricsTracer).toOtelMetricAttrs()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/metrics.go:569 +0x204
  cloud.google.com/go/spanner.recordAttemptCompletion()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/metrics.go:660 +0x2a4
  cloud.google.com/go/spanner.(*RowIterator).Next.func1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:173 +0x124
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:610 +0x5d
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:578 +0x472
  cloud.google.com/go/spanner.(*RowIterator).Next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:182 +0x4e4
  github.com/googleapis/go-sql-spanner.(*readOnlyRowIterator).Next()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/transaction.go:66 +0x35
  github.com/googleapis/go-sql-spanner.(*rows).Columns.(*rows).getColumns.func1()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:66 +0x4d
  sync.(*Once).doSlow()
      /usr/local/go/src/sync/once.go:78 +0xe1
  sync.(*Once).Do()
      /usr/local/go/src/sync/once.go:69 +0x44
  github.com/googleapis/go-sql-spanner.(*rows).getColumns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:65 +0x6e
  github.com/googleapis/go-sql-spanner.(*rows).Columns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:49 +0x25
  database/sql.(*Rows).nextLocked()
      /usr/local/go/src/database/sql/sql.go:3063 +0x15a
  database/sql.(*Rows).Next.func1()
      /usr/local/go/src/database/sql/sql.go:3041 +0x3c
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3574 +0xa6
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3040 +0x124
  // ... APPLICATION SPECIFIC CODE ...
Goroutine 32665 (running) created at:
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:680 +0xde4
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:676 +0x89
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:618 +0x9c8
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:578 +0x472
  cloud.google.com/go/spanner.(*RowIterator).Next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:182 +0x4e4
  github.com/googleapis/go-sql-spanner.(*readOnlyRowIterator).Next()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/transaction.go:66 +0x35
  github.com/googleapis/go-sql-spanner.(*rows).Columns.(*rows).getColumns.func1()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:66 +0x4d
  sync.(*Once).doSlow()
      /usr/local/go/src/sync/once.go:78 +0xe1
  sync.(*Once).Do()
      /usr/local/go/src/sync/once.go:69 +0x44
  github.com/googleapis/go-sql-spanner.(*rows).getColumns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:65 +0x6e
  github.com/googleapis/go-sql-spanner.(*rows).Columns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:49 +0x25
  database/sql.(*Rows).nextLocked()
      /usr/local/go/src/database/sql/sql.go:3063 +0x15a
  database/sql.(*Rows).Next.func1()
      /usr/local/go/src/database/sql/sql.go:3041 +0x3c
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3574 +0xa6
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3040 +0x124
  // ... APPLICATION SPECIFIC CODE ...
Third example 
==================
WARNING: DATA RACE
Write at 0x00c008a8de28 by goroutine 32665:
  cloud.google.com/go/spanner.(*attemptTracer).setDirectPathUsed()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/metrics.go:512 +0x364
  cloud.google.com/go/spanner.(*wrappedStream).RecvMsg()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/client.go:774 +0x2d2
  cloud.google.com/go/spanner.(*wrappedStream).RecvMsg()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/client.go:750 +0x82
  cloud.google.com/go/spanner/apiv1/spannerpb.(*spannerExecuteStreamingSqlClient).Recv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/apiv1/spannerpb/spanner.pb.go:4268 +0x65
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv.func1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:681 +0x3a
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv.gowrap1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:686 +0x4f
Previous read at 0x00c008a8de28 by goroutine 32446:
  cloud.google.com/go/spanner.(*builtinMetricsTracer).toOtelMetricAttrs()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/metrics.go:571 +0x4c5
  cloud.google.com/go/spanner.recordAttemptCompletion()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/metrics.go:660 +0x2a4
  cloud.google.com/go/spanner.(*RowIterator).Next.func1()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:173 +0x124
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:610 +0x5d
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:578 +0x472
  cloud.google.com/go/spanner.(*RowIterator).Next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:182 +0x4e4
  github.com/googleapis/go-sql-spanner.(*readOnlyRowIterator).Next()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/transaction.go:66 +0x35
  github.com/googleapis/go-sql-spanner.(*rows).Columns.(*rows).getColumns.func1()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:66 +0x4d
  sync.(*Once).doSlow()
      /usr/local/go/src/sync/once.go:78 +0xe1
  sync.(*Once).Do()
      /usr/local/go/src/sync/once.go:69 +0x44
  github.com/googleapis/go-sql-spanner.(*rows).getColumns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:65 +0x6e
  github.com/googleapis/go-sql-spanner.(*rows).Columns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:49 +0x25
  database/sql.(*Rows).nextLocked()
      /usr/local/go/src/database/sql/sql.go:3063 +0x15a
  database/sql.(*Rows).Next.func1()
      /usr/local/go/src/database/sql/sql.go:3041 +0x3c
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3574 +0xa6
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3040 +0x124
  // ... APPLICATION SPECIFIC CODE ...
Goroutine 32665 (running) created at:
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:680 +0xde4
  cloud.google.com/go/spanner.(*resumableStreamDecoder).tryRecv()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:676 +0x89
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:618 +0x9c8
  cloud.google.com/go/spanner.(*resumableStreamDecoder).next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:578 +0x472
  cloud.google.com/go/spanner.(*RowIterator).Next()
      /go/pkg/mod/cloud.google.com/go/spanner@v1.83.0/read.go:182 +0x4e4
  github.com/googleapis/go-sql-spanner.(*readOnlyRowIterator).Next()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/transaction.go:66 +0x35
  github.com/googleapis/go-sql-spanner.(*rows).Columns.(*rows).getColumns.func1()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:66 +0x4d
  sync.(*Once).doSlow()
      /usr/local/go/src/sync/once.go:78 +0xe1
  sync.(*Once).Do()
      /usr/local/go/src/sync/once.go:69 +0x44
  github.com/googleapis/go-sql-spanner.(*rows).getColumns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:65 +0x6e
  github.com/googleapis/go-sql-spanner.(*rows).Columns()
      /go/pkg/mod/github.com/googleapis/go-sql-spanner@v1.11.1-0.20250214171559-1bccea5dfec5/rows.go:49 +0x25
  database/sql.(*Rows).nextLocked()
      /usr/local/go/src/database/sql/sql.go:3063 +0x15a
  database/sql.(*Rows).Next.func1()
      /usr/local/go/src/database/sql/sql.go:3041 +0x3c
  database/sql.withLock()
      /usr/local/go/src/database/sql/sql.go:3574 +0xa6
  database/sql.(*Rows).Next()
      /usr/local/go/src/database/sql/sql.go:3040 +0x124
  // ... APPLICATION SPECIFIC CODE ...

Expected behavior

No data race.

Actual behavior

There's a data race.

Additional context

Still debugging to try and find a smaller easily reproducible example.

Metadata

Metadata

Assignees

Labels

api: spannerIssues related to the Spanner API.triage meI really want to be triaged.

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions