state: DATA RACE in watcher

Bug #1586244 reported by Dave Cheney
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Canonical Juju
Fix Released
Critical
Dave Cheney

Bug Description

As seen in
    http://reports.vapour.ws/releases/issue/574dbf05749a5619c114b5c6

=== RUN TestPackage
==================
WARNING: DATA RACE
Read at 0x00c420630e20 by goroutine 50:
  github.com/juju/juju/state.(*backingMachine).updated()
      /home/dfc/src/github.com/juju/juju/state/allwatcher.go:186 +0x923
  github.com/juju/juju/state.(*allModelWatcherStateBacking).Changed()
      /home/dfc/src/github.com/juju/juju/state/allwatcher.go:1165 +0x636
  github.com/juju/juju/state.(*storeManager).loop()
      /home/dfc/src/github.com/juju/juju/state/multiwatcher.go:229 +0x346
  github.com/juju/juju/state.newStoreManager.func1()
      /home/dfc/src/github.com/juju/juju/state/multiwatcher.go:198 +0x76

Previous write at 0x00c420630e20 by goroutine 86:
  github.com/juju/juju/state.substNilSinceTimeForEntityNoCheck()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:396 +0x1ea
  github.com/juju/juju/state.deltaMap()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3165 +0x26c
  github.com/juju/juju/state.checkDeltasEqual()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3155 +0x59
  github.com/juju/juju/state.(*allModelWatcherStateSuite).TestStateWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:1477 +0x2056
  runtime.call32()
      /home/dfc/go/src/runtime/asm_amd64.s:479 +0x4b
  reflect.Value.Call()
      /home/dfc/go/src/reflect/value.go:302 +0xc0
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:772 +0xab0
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:666 +0x89

Goroutine 50 (running) created at:
  github.com/juju/juju/state.newStoreManager()
      /home/dfc/src/github.com/juju/juju/state/multiwatcher.go:207 +0x33c
  github.com/juju/juju/state.newTestWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3045 +0x46
  github.com/juju/juju/state.newTestAllModelWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3032 +0x64
  github.com/juju/juju/state.(*allModelWatcherStateSuite).TestStateWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:1364 +0x774
  runtime.call32()
      /home/dfc/go/src/runtime/asm_amd64.s:479 +0x4b
  reflect.Value.Call()
      /home/dfc/go/src/reflect/value.go:302 +0xc0
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:772 +0xab0
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:666 +0x89

Goroutine 86 (running) created at:
  gopkg.in/check%2ev1.(*suiteRunner).forkCall()
      /home/dfc/src/gopkg.in/check.v1/check.go:667 +0x419
  gopkg.in/check%2ev1.(*suiteRunner).forkTest()
      /home/dfc/src/gopkg.in/check.v1/check.go:804 +0x131
  gopkg.in/check%2ev1.(*suiteRunner).runTest()
      /home/dfc/src/gopkg.in/check.v1/check.go:809 +0x46
  gopkg.in/check%2ev1.(*suiteRunner).run()
      /home/dfc/src/gopkg.in/check.v1/check.go:615 +0x1c5
  gopkg.in/check%2ev1.Run()
      /home/dfc/src/gopkg.in/check.v1/run.go:92 +0x5a
  gopkg.in/check%2ev1.RunAll()
      /home/dfc/src/gopkg.in/check.v1/run.go:84 +0x112
  gopkg.in/check%2ev1.TestingT()
      /home/dfc/src/gopkg.in/check.v1/run.go:72 +0x708
  github.com/juju/testing.MgoTestPackage()
      /home/dfc/src/github.com/juju/testing/mgo.go:356 +0xb8
  github.com/juju/juju/testing.MgoTestPackage()
      /home/dfc/src/github.com/juju/juju/testing/mgo.go:15 +0x54
  github.com/juju/juju/state_test.TestPackage()
      /home/dfc/src/github.com/juju/juju/state/package_test.go:13 +0x38
  testing.tRunner()
      /home/dfc/go/src/testing/testing.go:610 +0xc9
==================
==================
WARNING: DATA RACE
Read at 0x00c420630e70 by goroutine 50:
  github.com/juju/juju/state.(*backingMachine).updated()
      /home/dfc/src/github.com/juju/juju/state/allwatcher.go:187 +0x9b6
  github.com/juju/juju/state.(*allModelWatcherStateBacking).Changed()
      /home/dfc/src/github.com/juju/juju/state/allwatcher.go:1165 +0x636
  github.com/juju/juju/state.(*storeManager).loop()
      /home/dfc/src/github.com/juju/juju/state/multiwatcher.go:229 +0x346
  github.com/juju/juju/state.newStoreManager.func1()
      /home/dfc/src/github.com/juju/juju/state/multiwatcher.go:198 +0x76

Previous write at 0x00c420630e70 by goroutine 86:
  github.com/juju/juju/state.substNilSinceTimeForEntityNoCheck()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:397 +0x20d
  github.com/juju/juju/state.deltaMap()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3165 +0x26c
  github.com/juju/juju/state.checkDeltasEqual()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3155 +0x59
  github.com/juju/juju/state.(*allModelWatcherStateSuite).TestStateWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:1477 +0x2056
  runtime.call32()
      /home/dfc/go/src/runtime/asm_amd64.s:479 +0x4b
  reflect.Value.Call()
      /home/dfc/go/src/reflect/value.go:302 +0xc0
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:772 +0xab0
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:666 +0x89

Goroutine 50 (running) created at:
  github.com/juju/juju/state.newStoreManager()
      /home/dfc/src/github.com/juju/juju/state/multiwatcher.go:207 +0x33c
  github.com/juju/juju/state.newTestWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3045 +0x46
  github.com/juju/juju/state.newTestAllModelWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:3032 +0x64
  github.com/juju/juju/state.(*allModelWatcherStateSuite).TestStateWatcher()
      /home/dfc/src/github.com/juju/juju/state/allwatcher_internal_test.go:1364 +0x774
  runtime.call32()
      /home/dfc/go/src/runtime/asm_amd64.s:479 +0x4b
  reflect.Value.Call()
      /home/dfc/go/src/reflect/value.go:302 +0xc0
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:772 +0xab0
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/dfc/src/gopkg.in/check.v1/check.go:666 +0x89

Goroutine 86 (running) created at:
  gopkg.in/check%2ev1.(*suiteRunner).forkCall()
      /home/dfc/src/gopkg.in/check.v1/check.go:667 +0x419
  gopkg.in/check%2ev1.(*suiteRunner).forkTest()
      /home/dfc/src/gopkg.in/check.v1/check.go:804 +0x131
  gopkg.in/check%2ev1.(*suiteRunner).runTest()
      /home/dfc/src/gopkg.in/check.v1/check.go:809 +0x46
  gopkg.in/check%2ev1.(*suiteRunner).run()
      /home/dfc/src/gopkg.in/check.v1/check.go:615 +0x1c5
  gopkg.in/check%2ev1.Run()
      /home/dfc/src/gopkg.in/check.v1/run.go:92 +0x5a
  gopkg.in/check%2ev1.RunAll()
      /home/dfc/src/gopkg.in/check.v1/run.go:84 +0x112
  gopkg.in/check%2ev1.TestingT()
      /home/dfc/src/gopkg.in/check.v1/run.go:72 +0x708
  github.com/juju/testing.MgoTestPackage()
      /home/dfc/src/github.com/juju/testing/mgo.go:356 +0xb8
  github.com/juju/juju/testing.MgoTestPackage()
      /home/dfc/src/github.com/juju/juju/testing/mgo.go:15 +0x54
  github.com/juju/juju/state_test.TestPackage()
      /home/dfc/src/github.com/juju/juju/state/package_test.go:13 +0x38
  testing.tRunner()
      /home/dfc/go/src/testing/testing.go:610 +0xc9
==================

Changed in juju-core:
assignee: nobody → Dave Cheney (dave-cheney)
Revision history for this message
Dave Cheney (dave-cheney) wrote :

The problem is the values returned from multiWatcherStore.Get are being mutated by the tests. This is in direct contravention of the contract of this method.

// Get returns the stored entity with the given
// id, or nil if none was found. The contents of the returned entity
// should not be changed.
func (a *multiwatcherStore) Get(id multiwatcher.EntityId) multiwatcher.EntityInfo {

However methods like

// substNilSinceTimeForEntities zeros out any updated timestamps for unit
// or service status values so we can easily check the results.
func substNilSinceTimeForEntities(c *gc.C, entities []multiwatcher.EntityInfo) {

Do precisely this, corrupting the state of the data stored in the multiWatcherStore

tags: removed: blocker
Changed in juju-core:
status: New → Triaged
assignee: Dave Cheney (dave-cheney) → nobody
Changed in juju-core:
status: Triaged → Fix Committed
status: Fix Committed → In Progress
assignee: nobody → Dave Cheney (dave-cheney)
tags: added: blocker
Curtis Hovey (sinzui)
description: updated
tags: added: ci regression
Changed in juju-core:
status: In Progress → Fix Committed
Curtis Hovey (sinzui)
Changed in juju-core:
status: Fix Committed → Fix Released
affects: juju-core → juju
Changed in juju:
milestone: 2.0-beta8 → none
milestone: none → 2.0-beta8
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.