cue-lang / cue

The home of the CUE language! Validate and define text-based and dynamic configuration
https://cuelang.org
Apache License 2.0
5.14k stars 294 forks source link

cue: data race when calling cue.Fill concurrently #652

Closed cueckoo closed 1 year ago

cueckoo commented 3 years ago

Originally opened by @myitcv in https://github.com/cuelang/cue/issues/652

What version of CUE are you using (cue version)?

$ cue version
v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb

Does this issue reproduce with the latest release?

Yes

What did you do?

cat <<'EOD' | testscript -e GOPATH="$(go env GOPATH)" -e GOBUILD="$(go env GOBUILD)"

exec go mod tidy
exec go run -race main.go

-- go.mod --
module mod.com

go 1.16

require cuelang.org/go v0.3.0-beta.2.0.20210120153448-c58e0ffc4c74
-- main.cue --
package main

#A: {
 type: "a"
 val:  #C
}

#C: string

tasks: {
 a: {
  $id: "a"
 }
 b: {
  $id: "b"
 }
}
-- main.go --
package main

import (
 "cuelang.org/go/cue"
 "cuelang.org/go/cue/load"
)

func main() {
 bis := load.Instances([]string{"."}, nil)
 is := cue.Build(bis)
 inst := is[0]

 schema := inst.LookupDef("#A")
 go fill(schema)
 go fill(schema)
}

func fill(schema cue.Value) {
 for i := 0; i < 100000; i++ {
  schema.Fill(5)
 }
}
EOD

Note, you might need to re-run this a few times (or increase the counter limit in the for loop)

What did you expect to see?

Success

What did you see instead?

[stderr]
==================
WARNING: DATA RACE
Write at 0x00c00034b6a0 by goroutine 19:
  cuelang.org/go/internal/core/adt.(*nodeContext).evalExpr()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1063 +0x136
  cuelang.org/go/internal/core/adt.(*nodeContext).addExprConjunct()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1049 +0x2f4
  cuelang.org/go/internal/core/adt.(*Unifier).Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:250 +0x1644
  cuelang.org/go/internal/core/adt.(*nodeContext).completeArcs()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:567 +0x21c
  cuelang.org/go/internal/core/adt.(*nodeContext).postDisjunct()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:538 +0x5d3
  cuelang.org/go/internal/core/adt.(*nodeContext).expandDisjuncts()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/disjunct.go:142 +0x1d07
  cuelang.org/go/internal/core/adt.(*Unifier).Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:305 +0x3b0
  cuelang.org/go/internal/core/adt.(*Vertex).Finalize()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/composite.go:405 +0x148
  cuelang.org/go/cue.Value.Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1778 +0x127
  cuelang.org/go/cue.Value.Fill()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1648 +0x288
  main.fill()
      $WORK/main.go:20 +0x78

Previous read at 0x00c00034b6a0 by goroutine 20:
  cuelang.org/go/internal/core/adt.(*Vertex).Status()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/composite.go:269 +0x265
  cuelang.org/go/internal/core/adt.(*nodeContext).addVertexConjuncts()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1168 +0x871
  cuelang.org/go/internal/core/adt.(*nodeContext).addExprConjunct()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1024 +0x1dd
  cuelang.org/go/internal/core/adt.(*Unifier).Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:250 +0x1644
  cuelang.org/go/internal/core/adt.(*Vertex).Finalize()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/composite.go:405 +0x148
  cuelang.org/go/cue.Value.Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1778 +0x127
  cuelang.org/go/cue.Value.Fill()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1648 +0x288
  main.fill()
      $WORK/main.go:20 +0x78

Goroutine 19 (running) created at:
  main.main()
      $WORK/main.go:14 +0x113

Goroutine 20 (running) created at:
  main.main()
      $WORK/main.go:15 +0x144
==================
==================
WARNING: DATA RACE
Read at 0x00c00034b6a8 by goroutine 19:
  cuelang.org/go/internal/core/adt.(*nodeContext).addVertexConjuncts()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1204 +0x728
  cuelang.org/go/internal/core/adt.(*nodeContext).addExprConjunct()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1024 +0x1dd
  cuelang.org/go/internal/core/adt.(*Unifier).Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:250 +0x1644
  cuelang.org/go/internal/core/adt.(*Vertex).Finalize()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/composite.go:405 +0x148
  cuelang.org/go/cue.Value.Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1778 +0x127
  cuelang.org/go/cue.Value.Fill()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1648 +0x288
  main.fill()
      $WORK/main.go:20 +0x78

Previous write at 0x00c00034b6a8 by goroutine 20:
  cuelang.org/go/internal/core/adt.(*nodeContext).addVertexConjuncts()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1210 +0x771
  cuelang.org/go/internal/core/adt.(*nodeContext).addExprConjunct()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:1024 +0x1dd
  cuelang.org/go/internal/core/adt.(*Unifier).Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/eval.go:250 +0x1644
  cuelang.org/go/internal/core/adt.(*Vertex).Finalize()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/internal/core/adt/composite.go:405 +0x148
  cuelang.org/go/cue.Value.Unify()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1778 +0x127
  cuelang.org/go/cue.Value.Fill()
      /home/myitcv/gostuff/pkg/mod/cuelang.org/go@v0.3.0-beta.2.0.20210118191218-f0c025c1a4cb/cue/types.go:1648 +0x288
  main.fill()
      $WORK/main.go:20 +0x78

Goroutine 19 (running) created at:
  main.main()
      $WORK/main.go:14 +0x113

Goroutine 20 (running) created at:
  main.main()
      $WORK/main.go:15 +0x144
==================
Found 2 data race(s)
exit status 66
[exit status 1]
FAIL: /tmp/testscript736373366/-/script.txt:3: unexpected command failure
error running <stdin> in /tmp/testscript736373366/-

cc @shykes

Note the above repro is using c58e0ffc4c74. However, the underlying problem also exists with v0.3.0-alpha6, albeit a different kind of problem (hence stack traces vary). Critically, this reproducer does not trigger the issue for v0.3.0-alpha6

cueckoo commented 3 years ago

Original reply by @myitcv in https://github.com/cuelang/cue/issues/652#issuecomment-763909803

Further analysis: LookupPath also races with a Fill call. Which may or may not point to a problem in the code path LookupPath is following if it's reading that same state?

cueckoo commented 3 years ago

Original reply by @mpvl in https://github.com/cuelang/cue/issues/652#issuecomment-766156066

Analysis: the race is caused by the reference cycle detection, which modifies fields in Vertex even when it is already Finalized.

So to fix this, the reference cycle detection algorithm needs to be changed. One idea is the following: the fields are only necessary to detect the cycle for fields that are already finalized; the first time the cycle is found, it uses a different mechanism. There is a possible optimization where identical arcs (i.e. those that evaluate without an error after the cycle detection) are evaluated once and share the same data structure. This is a great optimization. But it seemingly also would obviate the need for the additional cycle check, the one that causes things to be not thread-safe.

The following would be needed to implement structure sharing:

mpvl commented 1 year ago

This should have been fixed. Many concurrency fixes have gone in.

Verified this particular one.