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

runtime,go/token: data race on FileSet.last #48940

Open
bcmills opened this issue Oct 13, 2021 · 3 comments
Open

runtime,go/token: data race on FileSet.last #48940

bcmills opened this issue Oct 13, 2021 · 3 comments

Comments

@bcmills
Copy link
Member

@bcmills bcmills commented Oct 13, 2021

greplogs --dashboard -md -l -e '(?m)WARNING: DATA RACE\n.*\n go/token'

2021-10-13T00:11:47-4fb2e1c/freebsd-amd64-race

See previously #4345.

@bcmills bcmills added this to the Backlog milestone Oct 13, 2021
@bcmills
Copy link
Member Author

@bcmills bcmills commented Oct 13, 2021

==================
WARNING: DATA RACE
Read at 0x00c0001de038 by goroutine 58:
  go/token.(*FileSet).file()
      /tmp/workdir/go/src/go/token/position.go:476 +0x4a
  go/token.(*FileSet).PositionFor()
      /tmp/workdir/go/src/go/token/position.go:514 +0x5e
  go/ast.lineAt()
      /tmp/workdir/go/src/go/ast/import.go:56 +0x3e5
  go/ast.SortImports()
      /tmp/workdir/go/src/go/ast/import.go:45 +0x3ce
  go/format.Node()
      /tmp/workdir/go/src/go/format/format.go:82 +0x384
  cmd/fix.gofmtFile()
      /tmp/workdir/go/src/cmd/fix/main.go:110 +0xa8
  cmd/fix.parseFixPrint()
      /tmp/workdir/go/src/cmd/fix/main_test.go:68 +0x434
  cmd/fix.TestRewrite.func1()
      /tmp/workdir/go/src/cmd/fix/main_test.go:109 +0x36e
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1377 +0x213
  testing.(*T).Run.func1()
      /tmp/workdir/go/src/testing/testing.go:1424 +0x47

Previous write at 0x00c0001de038 by goroutine 16:
  go/token.(*FileSet).file()
      /tmp/workdir/go/src/go/token/position.go:487 +0x1ce
  go/token.(*FileSet).PositionFor()
      /tmp/workdir/go/src/go/token/position.go:514 +0x5e
  go/printer.(*printer).lineFor()
      /tmp/workdir/go/src/go/printer/printer.go:204 +0x47d
  go/printer.(*printer).exprList()
      /tmp/workdir/go/src/go/printer/nodes.go:148 +0x3b0
  go/printer.(*printer).spec()
      /tmp/workdir/go/src/go/printer/nodes.go:1628 +0x3f0
  go/printer.(*printer).genDecl()
      /tmp/workdir/go/src/go/printer/nodes.go:1691 +0x479
  go/printer.(*printer).decl()
      /tmp/workdir/go/src/go/printer/nodes.go:1839 +0xa6
  go/printer.(*printer).declList()
      /tmp/workdir/go/src/go/printer/nodes.go:1884 +0x544
  go/printer.(*printer).file()
      /tmp/workdir/go/src/go/printer/nodes.go:1892 +0x14e
  go/printer.(*printer).printNode()
      /tmp/workdir/go/src/go/printer/printer.go:1159 +0x85c
  go/printer.(*Config).fprint()
      /tmp/workdir/go/src/go/printer/printer.go:1316 +0x1af
  go/printer.(*Config).Fprint()
      /tmp/workdir/go/src/go/printer/printer.go:1378 +0x4d5
  go/format.Node()
      /tmp/workdir/go/src/go/format/format.go:91 +0x3e
  cmd/fix.gofmtFile()
      /tmp/workdir/go/src/cmd/fix/main.go:110 +0xa8
  cmd/fix.parseFixPrint()
      /tmp/workdir/go/src/cmd/fix/main_test.go:68 +0x434
  cmd/fix.TestRewrite.func1()
      /tmp/workdir/go/src/cmd/fix/main_test.go:83 +0x84
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1377 +0x213
  testing.(*T).Run.func1()
      /tmp/workdir/go/src/testing/testing.go:1424 +0x47

Goroutine 58 (running) created at:
  testing.(*T).Run()
      /tmp/workdir/go/src/testing/testing.go:1424 +0x724
  cmd/fix.TestRewrite()
      /tmp/workdir/go/src/cmd/fix/main_test.go:80 +0x1a4
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1377 +0x213
  testing.(*T).Run.func1()
      /tmp/workdir/go/src/testing/testing.go:1424 +0x47

Goroutine 16 (running) created at:
  testing.(*T).Run()
      /tmp/workdir/go/src/testing/testing.go:1424 +0x724
  cmd/fix.TestRewrite()
      /tmp/workdir/go/src/cmd/fix/main_test.go:80 +0x1a4
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1377 +0x213
  testing.(*T).Run.func1()
      /tmp/workdir/go/src/testing/testing.go:1424 +0x47
==================

Loading

@bcmills
Copy link
Member Author

@bcmills bcmills commented Oct 13, 2021

The odd thing about this race is that both the read and the write appear to be synchronized.

The read is here, under an RLock:

go/src/go/token/position.go

Lines 474 to 479 in e8f99da

s.mutex.RLock()
// common case: p is in last file
if f := s.last; f != nil && f.base <= int(p) && int(p) <= f.base+f.size {
s.mutex.RUnlock()
return f
}

The write is here, under a write-lock:

go/src/go/token/position.go

Lines 485 to 489 in e8f99da

s.mutex.RUnlock()
s.mutex.Lock()
s.last = f // race is ok - s.last is only a cache
s.mutex.Unlock()
return f

Loading

@bcmills
Copy link
Member Author

@bcmills bcmills commented Oct 14, 2021

For now the best theory I have for this failure is “unrelated memory corruption” (#46272). 🤷‍♂️

Loading

@bcmills bcmills changed the title go/token: data race on FileSet.last runtime,go/token: data race on FileSet.last Oct 14, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
1 participant