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

Attempting to scan JSON column into json.RawMessage sets off Go race detector, returns dirty driver memory #437

Closed
kevinburkeshyp opened this issue Feb 15, 2016 · 0 comments

Comments

@kevinburkeshyp
Copy link

I'm adding this comment because I just spent ~3 hours investigating this. I had a type like this:

type Foo struct {
    Id       string `json:"id"`
    Name     string           `json:"name"`
    Attempts uint8            `json:"attempts"`
    Status   string           `json:"status"`
    Data     *json.RawMessage `json:"data"`
}

matching this schema

CREATE TABLE queued_jobs (
    id text PRIMARY KEY,
    name TEXT NOT NULL,
    attempts SMALLINT NOT NULL,
    status job_status NOT NULL,
    data JSONB NOT NULL
);

I attempted to scan into the json.RawMessage like this

    foo := new(Foo)
    err := Conn.QueryRow(query, name).Scan(&foo.Id, &foo.Name, &foo.Attempts, &foo.Status, &foo.Data)

The contents of foo.Data were very occasionally the data I passed in, usually random raw PG strings. The Go race detector also reported a data race, something like this:

=== RUN   TestWorkerMakesExactlyOneRequest
trying to acquire
trying to acquire
2016/02/15 11:31:34 processing job job_acfcb5b8-b24a-445b-6641-faa3863b4226
&main.QueuedJob{Id:types.PrefixUUID{UUID:(*uuid.UUID)(0xc82013a0c0), Prefix:"job_"}, Name:"echo", Attempts:0x3, Status:"in-progress", Data:(*json.RawMessage)(0xc8201461a0)}
==================
WARNING: DATA RACE
Read by goroutine 8:
  runtime.slicebytetostring()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/runtime/string.go:75 +0x0

Previous write by goroutine 9:
  runtime.slicecopy()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/runtime/slice.go:110 +0x0
  bufio.(*Reader).Read()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/bufio/bufio.go:214 +0x738
  io.ReadAtLeast()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/io/io.go:298 +0x118
  io.ReadFull()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/io/io.go:316 +0x76
  github.com/lib/pq.(*conn).recvMessage()
      /Users/burke/code/go/src/github.com/lib/pq/conn.go:834 +0x4ea
  github.com/lib/pq.(*conn).recv1Buf()
      /Users/burke/code/go/src/github.com/lib/pq/conn.go:870 +0x3c
  github.com/lib/pq.(*conn).recv1()
      /Users/burke/code/go/src/github.com/lib/pq/conn.go:891 +0xc7
  github.com/lib/pq.(*conn).readStatementDescribeResponse()
      /Users/burke/code/go/src/github.com/lib/pq/conn.go:1538 +0xa6
  github.com/lib/pq.(*conn).prepareTo()
      /Users/burke/code/go/src/github.com/lib/pq/conn.go:661 +0x1455
  github.com/lib/pq.(*conn).Query()
      /Users/burke/code/go/src/github.com/lib/pq/conn.go:718 +0x5b7
  database/sql.(*DB).queryConn()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/database/sql/sql.go:977 +0x228
  database/sql.(*DB).query()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/database/sql/sql.go:964 +0x176
  database/sql.(*DB).Query()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/database/sql/sql.go:947 +0xb9
  database/sql.(*DB).QueryRow()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/database/sql/sql.go:1028 +0x70
  github.com/kevinburke/data-race.Acquire()
      /Users/burke/code/go/src/github.com/kevinburke/data-race/race.go:59 +0x1d8
  github.com/kevinburke/data-race.work.func1()
      /Users/burke/code/go/src/github.com/kevinburke/data-race/race.go:72 +0x1b4

Goroutine 8 (running) created at:
  github.com/kevinburke/data-race.work()
      /Users/burke/code/go/src/github.com/kevinburke/data-race/race.go:93 +0x56
  github.com/kevinburke/data-race.TestWorkerMakesExactlyOneRequest()
      /Users/burke/code/go/src/github.com/kevinburke/data-race/race_test.go:54 +0x8b0
  testing.tRunner()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/testing/testing.go:456 +0xdc

Goroutine 9 (running) created at:
  github.com/kevinburke/data-race.work()
      /Users/burke/code/go/src/github.com/kevinburke/data-race/race.go:93 +0x56
  github.com/kevinburke/data-race.TestWorkerMakesExactlyOneRequest()
      /Users/burke/code/go/src/github.com/kevinburke/data-race/race_test.go:54 +0x8b0
  testing.tRunner()
      /opt/boxen/homebrew/Cellar/go/1.5.3/libexec/src/testing/testing.go:456 +0xdc
==================
"atus\x00\x00\x00\x8ec\x00\b\x00\x00\x8eT\x00\x04\xff\xff\xff\xff\x00\x00data\x00\x00\x00\x8ec\x00\t\x00\x00\x0e\xda"
goroutine 37 [running]:
github.com/kevinburke/data-race.work.func1(0xc820120060, 0x44f5f0, 0x4)
    /Users/burke/code/go/src/github.com/kevinburke/data-race/race.go:78 +0x5b6
created by github.com/kevinburke/data-race.work
    /Users/burke/code/go/src/github.com/kevinburke/data-race/race.go:93 +0x57

dumped stack
json: error calling MarshalJSON for type *json.RawMessage: invalid character 'a' looking for beginning of value

It looks like the root cause is golang/go#13905. The workaround is to scan into a *[]byte and then convert to json.RawMessage once it's scanned.

Among other things, this means the advice I wrote in #381 is misleading at best.

@kevinburkeshyp kevinburkeshyp changed the title Attempting to scan JSON column into json.RawMessage returns dirty driver memory Attempting to scan JSON column into json.RawMessage sets off Go race detector, returns dirty driver memory Feb 15, 2016
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

1 participant