Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tdsBuffer data race in transaction query with OUTPUT #171

Open
pirm-in opened this issue Jan 26, 2024 · 1 comment
Open

tdsBuffer data race in transaction query with OUTPUT #171

pirm-in opened this issue Jan 26, 2024 · 1 comment

Comments

@pirm-in
Copy link

pirm-in commented Jan 26, 2024

Versions
go 1.21
github.com/microsoft/go-mssqldb v1.6.0

Describe the bug
Running $ go test ./... -race results in a data race. See stack trace below. The issue seems to happen when func (r *tdsBuffer) readNextPacket() is writing to a field of the tdsBuffer instance .

During the transaction there are two insert statements happening

rows, err := tx.NamedQuery(`
        INSERT INTO Events (Type, Value, Description, ...)
        OUTPUT inserted.Uuid, inserted.Id
        VALUES (Type, :Value, :Description, ...)
    `, row)

and later this is called

func (h *EventHistory) TxStore(tx *sqlx.Tx) error {
	_, err := tx.Exec(`
          INSERT INTO EventHistory (EventId, Data) 
          VALUES (@event_id, @data)
        `,
		sql.Named("event_id", h.EventId),
		sql.Named("data", h.Data))

	return err
}

Edit: I just noticed the data race does not occur when there is no OUTPUT field in the NamedQuery. With the following query there is no data race:

rows, err := tx.NamedQuery(`
        INSERT INTO Events (Type, Value, Description, ...)
        VALUES (Type, :Value, :Description, ...)
    `, row)

Stack trace:

2024/01/26 11:56:53 INFO Database connection pool max_idle=40 max_open=40
==================
WARNING: DATA RACE
Write at 0x00c0000b6a60 by goroutine 60:
  github.com/microsoft/go-mssqldb.(*tdsBuffer).readNextPacket()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/buf.go:184 +0x4e4
  github.com/microsoft/go-mssqldb.(*tdsBuffer).BeginRead()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/buf.go:192 +0x16e
  github.com/microsoft/go-mssqldb.processSingleResponse()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/token.go:961 +0x148
  github.com/microsoft/go-mssqldb.startReading.func1()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/token.go:1145 +0x8f

Previous write at 0x00c0000b6a60 by goroutine 58:
  github.com/microsoft/go-mssqldb.(*tdsBuffer).ReadByte()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/buf.go:210 +0x126
  github.com/microsoft/go-mssqldb.(*tdsBuffer).byte()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/buf.go:215 +0x504
  github.com/microsoft/go-mssqldb.processSingleResponse()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/token.go:982 +0x4e3
  github.com/microsoft/go-mssqldb.startReading.func1()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/token.go:1145 +0x8f

Goroutine 60 (running) created at:
  github.com/microsoft/go-mssqldb.startReading()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/token.go:1145 +0x1da
  github.com/microsoft/go-mssqldb.(*Stmt).processExec()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/mssql.go:814 +0xd2
  github.com/microsoft/go-mssqldb.(*Stmt).exec()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/mssql.go:807 +0x1aa
  github.com/microsoft/go-mssqldb.(*Stmt).ExecContext()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/mssql.go:1181 +0x3a7
  database/sql.ctxDriverStmtExec()
      /usr/local/go/src/database/sql/ctxutil.go:65 +0xec
  database/sql.resultFromStatement()
      /usr/local/go/src/database/sql/sql.go:2642 +0x1b0
  database/sql.(*DB).execDC()
      /usr/local/go/src/database/sql/sql.go:1694 +0x4fc
  database/sql.(*Tx).ExecContext()
      /usr/local/go/src/database/sql/sql.go:2478 +0x128
  database/sql.(*Tx).Exec()
      /usr/local/go/src/database/sql/sql.go:2487 +0x214
  /path/to/vkdb-svc/pkg/eventhistory/repository/mssql.(*EventHistory).TxStore()
      /path/to/html/vke/vkdb-svc/pkg/eventhistory/repository/mssql/model.go:19 +0x160
  /path/to/vkdb-svc/pkg/events/repository/mssql.(*EventRepository).Create.func1()
     /path/to/html/vke/vkdb-svc/pkg/events/repository/mssql/create.go:77 +0x409
  /path/to/vkdb-svc/pkg/db/mssql.WithTx()
     /path/to//html/vke/vkdb-svc/pkg/db/mssql/transaction.go:34 +0xfa
  /path/to/vkdb-svc/pkg/events/repository/mssql.(*EventRepository).Create()
      /path/to/html/vke/vkdb-svc/pkg/events/repository/mssql/create.go:42 +0x4cc
  /path/to/vkdb-svc/pkg/events.(*EventService).Create()
      /path/to/html/vke/vkdb-svc/pkg/events/service.go:72 +0x7f1
  /path/to/vkdb-svc/pkg/events.TestCreateEvent.func1()
      /path/to/html/vke/vkdb-svc/pkg/events/service_test.go:183 +0x9e
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1595 +0x238
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1648 +0x44

Goroutine 58 (finished) created at:
  github.com/microsoft/go-mssqldb.startReading()
      /path/to/go/pkg/mod/github.com/microsoft/[email protected]/token.go:1145 +0x1da
  github.com/microsoft/go-mssqldb.(*Stmt).processQueryResponse()
     /path/to/go/pkg/mod/github.com/microsoft/[email protected]/mssql.go:739 +0x11d
  github.com/microsoft/go-mssqldb.(*Stmt).queryContext()
     /path/to/go/pkg/mod/github.com/microsoft/[email protected]/mssql.go:734 +0x23a
  github.com/microsoft/go-mssqldb.(*Stmt).QueryContext()
     /path/to/go/pkg/mod/github.com/microsoft/[email protected]/mssql.go:1168 +0x3a7
  database/sql.ctxDriverStmtQuery()
      /usr/local/go/src/database/sql/ctxutil.go:82 +0xec
  database/sql.rowsiFromStatement()
      /usr/local/go/src/database/sql/sql.go:2808 +0x1f5
  database/sql.(*DB).queryDC()
      /usr/local/go/src/database/sql/sql.go:1778 +0x4d7
  database/sql.(*Tx).QueryContext()
      /usr/local/go/src/database/sql/sql.go:2497 +0x152
  database/sql.(*Tx).Query()
      /usr/local/go/src/database/sql/sql.go:2505 +0xaa
  github.com/jmoiron/sqlx.(*Tx).Queryx()
      /path/to/go/pkg/mod/github.com/jmoiron/[email protected]/sqlx.go:437 +0x54
  github.com/jmoiron/sqlx.NamedQuery()
      /path/to/go/pkg/mod/github.com/jmoiron/[email protected]/named.go:446 +0x162
  github.com/jmoiron/sqlx.(*Tx).NamedQuery()
      /path/to/go/pkg/mod/github.com/jmoiron/[email protected]/sqlx.go:419 +0x85
  /path/to/vkdb-svc/pkg/events/repository/mssql.(*EventRepository).Create.func1()
      /path/to/html/vke/vkdb-svc/pkg/events/repository/mssql/create.go:44 +0x5b
  /path/to/vkdb-svc/pkg/db/mssql.WithTx()
     /path/to/tml/vke/vkdb-svc/pkg/db/mssql/transaction.go:34 +0xfa
  /path/to/vkdb-svc/pkg/events/repository/mssql.(*EventRepository).Create()
     /path/to/html/vke/vkdb-svc/pkg/events/repository/mssql/create.go:42 +0x4cc
  /path/to/vkdb-svc/pkg/events.(*EventService).Create()
      /path/to/html/vke/vkdb-svc/pkg/events/service.go:72 +0x7f1
  /path/to/vkdb-svc/pkg/events.TestCreateEvent.func1()
      /path/to/html/vke/vkdb-svc/pkg/events/service_test.go:183 +0x9e
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1595 +0x238
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1648 +0x44

Further technical details

The database is running in a docker container with base image from mcr.microsoft.com/mssql/server:2022-latest
SELECT @@VERSION; shows

Microsoft SQL Server 2022 (RTM-CU5) (KB5026806) - 16.0.4045.3 (X64) 
        May 26 2023 12:52:08 
        Copyright (C) 2022 Microsoft Corporation
        Developer Edition (64-bit) on Linux (Ubuntu 20.04.6 LTS) <X64>

I cannot completely rule out that i am doing something wrong, but since I am not using go routines in my part of the code it seems more likely that it might indeed be an issue inside the go-mssqldb package.

@pirm-in pirm-in changed the title Data race when setting size of tdsBuffer in readNextPacket Data race in readNextPacket of tdsBuffer Jan 26, 2024
@pirm-in pirm-in changed the title Data race in readNextPacket of tdsBuffer Data race in readNextPacket of tdsBuffer when using sqlx.Transaction Jan 26, 2024
@pirm-in pirm-in changed the title Data race in readNextPacket of tdsBuffer when using sqlx.Transaction tdsBuffer data race in transaction query with OUTPUT Jan 29, 2024
@shueybubbles
Copy link
Collaborator

@pirm-in do you have a repro that doesn't use sqlx , just straight database/sql calls?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants