Loading...

XML

Word

Printable

Details

Type: Bug
Resolution: Fixed
Priority: Major
Fix Version/s: 5.0.0
Affects Version/s: 5.0.0
Component/s: fts
Labels:
None

Description

While enabling commit validation I see that sometimes a race is detected. It's not yet clear to me if the race is in cbft/cbgt, or if it was inadvertently introduced by me when fixing tests not have an ineffectual assignment:

go test -v -race -run=TestHandlersWithOnePartitionPrimaryFeedRollbackMoss

=== RUN   TestHandlersWithOnePartitionPrimaryFeedRollbackMoss

2017/04/02 12:46:12 manager: loading dataDir...

2017/04/02 12:46:12 manager: loading dataDir... done

2017/04/02 12:46:12 planner: awakes, op: kick, msg: start

2017/04/02 12:46:12 planner: once, reason: start

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: start

2017/04/02 12:46:12 janitor: JanitorOnce, err: janitor: skipped on nil planPIndexes

2017/04/02 12:46:12 planner: awakes, op: kick, msg: test-start-kick

2017/04/02 12:46:12 planner: once, reason: test-start-kick

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: test-start-kick

2017/04/02 12:46:12 janitor: JanitorOnce, err: janitor: skipped on nil planPIndexes

2017/04/02 12:46:12 http: serving assets from embedded data

2017/04/02 12:46:12 planner: awakes, op: kick, msg: cfg changed, key: indexDefs

2017/04/02 12:46:12 planner: once, reason: cfg changed, key: indexDefs

2017/04/02 12:46:12 manager_api: index definition created, indexType: fulltext-index, indexName: idx0, indexUUID: 89fd127dbb52bac1

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: cfg changed, key: planPIndexes

2017/04/02 12:46:12 janitor: pindexes to remove: 0

2017/04/02 12:46:12 janitor: pindexes to add: 1

2017/04/02 12:46:12   &{Name:idx0_89fd127dbb52bac1_f4dbdf21 UUID:28f2af2b24253732 IndexType:fulltext-index IndexName:idx0 IndexUUID:89fd127dbb52bac1 IndexParams:{} SourceType:primary SourceName: SourceUUID: SourceParams:{"numPartitions":1} SourcePartitions:0 Nodes:map[144dc592f29fa5fe:0xc42028afa0]}

2017/04/02 12:46:12 janitor: adding pindex: idx0_89fd127dbb52bac1_f4dbdf21

2017/04/02 12:46:12 janitor: feeds to remove: 0

2017/04/02 12:46:12 janitor: feeds to add: 1

2017/04/02 12:46:12   idx0_89fd127dbb52bac1

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: the plans have changed

2017/04/02 12:46:12 janitor: pindexes to remove: 0

2017/04/02 12:46:12 janitor: pindexes to add: 0

2017/04/02 12:46:12 janitor: feeds to remove: 0

2017/04/02 12:46:12 janitor: feeds to add: 0

2017/04/02 12:46:12 planner: awakes, op: kick, msg: api/CreateIndex, indexName: idx0

2017/04/02 12:46:12 planner: once, reason: api/CreateIndex, indexName: idx0

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: the plans have changed

2017/04/02 12:46:12 janitor: pindexes to remove: 0

2017/04/02 12:46:12 janitor: pindexes to add: 0

2017/04/02 12:46:12 janitor: feeds to remove: 0

2017/04/02 12:46:12 janitor: feeds to add: 0

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: cfg changed, key: planPIndexes

2017/04/02 12:46:12 janitor: pindexes to remove: 0

2017/04/02 12:46:12 janitor: pindexes to add: 0

2017/04/02 12:46:12 janitor: feeds to remove: 0

2017/04/02 12:46:12 janitor: feeds to add: 0

2017/04/02 12:46:12 bleve: dest rollback, partition: 0, key: "", seq: 0, val: "", err: <nil>

2017/04/02 12:46:12 pindex_bleve_rollback: path: tmp/test603797474/idx0_89fd127dbb52bac1_f4dbdf21.pindex, totSnapshotsExamined: 1

2017/04/02 12:46:12 pindex_bleve_rollback: path: tmp/test603797474/idx0_89fd127dbb52bac1_f4dbdf21.pindex, wasClosed: false, wasPartial: false, err: <nil>

2017/04/02 12:46:12 janitor: awakes, op: janitor_close_pindex, msg: api-ClosePIndex

2017/04/02 12:46:12 planner: awakes, op: kick, msg: after-rollback

==================

WARNING: DATA RACE

Read at 0x00c4201422e8 by goroutine 48:

  reflect.typedmemmove()

      /Users/mschoch/Documents/research/gosrc/src/runtime/mbarrier.go:253 +0x0

  reflect.packEface()

      /Users/mschoch/Documents/research/gosrc/src/reflect/value.go:112 +0x11c

  reflect.valueInterface()

      /Users/mschoch/Documents/research/gosrc/src/reflect/value.go:949 +0x18c

  reflect.Value.Interface()

      /Users/mschoch/Documents/research/gosrc/src/reflect/value.go:919 +0x51

  fmt.(*pp).printValue()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:694 +0x3aea

  fmt.(*pp).printValue()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:848 +0x27dc

  fmt.(*pp).printArg()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:682 +0x1b1

  fmt.(*pp).doPrintf()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:998 +0x1cad

  fmt.Sprintf()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:196 +0x77

  fmt.Errorf()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:205 +0x67

  github.com/couchbase/cbft.bleveIndexTargets.func1()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:1467 +0x502

  github.com/couchbase/cbgt.ConsistencyWaitGroup()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/pindex_consistency.go:130 +0x15e

  github.com/couchbase/cbft.bleveIndexTargets()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:1478 +0xff5

  github.com/couchbase/cbft.bleveIndexAlias()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:1349 +0x100

  github.com/couchbase/cbft.QueryBleve()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:531 +0xb48

  github.com/couchbase/cbgt/rest.(*QueryHandler).ServeHTTP()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/rest/rest_index.go:275 +0x4cb

  github.com/couchbase/cbgt/rest.(*HandlerWithRESTMeta).ServeHTTP()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/rest/rest.go:180 +0x16d

  github.com/couchbase/cbft.(*AuthVersionHandler).ServeHTTP()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest.go:147 +0x1c6

  github.com/gorilla/mux.(*Router).ServeHTTP()

      /Users/mschoch/go/src/github.com/gorilla/mux/mux.go:99 +0x358

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback.func7.1()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1747 +0x4a0

Previous write at 0x00c4201422e8 by goroutine 52:

  sync/atomic.AddInt32()

      /Users/mschoch/Documents/research/gosrc/src/runtime/race_amd64.s:269 +0xb

  sync.(*Mutex).Unlock()

      /Users/mschoch/Documents/research/gosrc/src/sync/mutex.go:111 +0x54

  github.com/couchbase/cbgt.restartPIndex()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/pindex.go:80 +0x86

Goroutine 48 (running) created at:

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback.func7()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1749 +0xbc

  github.com/couchbase/cbft.testRESTHandlers()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:142 +0xa0e

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1799 +0x2a2c

  github.com/couchbase/cbft.TestHandlersWithOnePartitionPrimaryFeedRollbackMoss()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1562 2017/04/02 12:46:12 planner: once, reason: after-rollback

+0x2f7

  testing.tRunner()

      /Users/mschoch/Documents/research/gosrc/src/testing/testing.go:657 +0x107

Goroutine 52 (running) created at:

  github.com/couchbase/cbgt.NewPIndex.func1()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/pindex.go:98 +0x85

  github.com/couchbase/cbft.(*BleveDest).Rollback()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve_rollback.go:59 +0x3f6

  github.com/couchbase/cbft.(*BleveDestPartition).Rollback()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve_rollback.go:173 +0x6e

  github.com/couchbase/cbgt.(*DestForwarder).Rollback()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/dest_forwarder.go:108 +0xe0

  github.com/couchbase/cbgt.(*PrimaryFeed).Rollback()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/feed_primary.go:174 +0x1e6

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback.func9()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1764 +0x97

  github.com/couchbase/cbft.testRESTHandlers()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:142 +0xa0e

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1799 +0x2a2c

  github.com/couchbase/cbft.TestHandlersWithOnePartitionPrimaryFeedRollbackMoss()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1562 +0x2f7

  testing.tRunner()

      /Users/mschoch/Documents/research/gosrc/src/testing/testing.go:657 +0x107

==================

==================

WARNING: DATA RACE

Read at 0x00c4201422f0 by goroutine 48:

  reflect.typedmemmove()

      /Users/mschoch/Documents/research/gosrc/src/runtime/mbarrier.go:253 +0x0

  reflect.packEface()

      /Users/mschoch/Documents/research/gosrc/src/reflect/value.go:112 +0x11c

  reflect.valueInterface()

      /Users/mschoch/Documents/research/gosrc/src/reflect/value.go:949 +0x18c

  reflect.Value.Interface()

      /Users/mschoch/Documents/research/gosrc/src/reflect/value.go:919 +0x51

  fmt.(*pp).printValue()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:694 +0x3aea

  fmt.(*pp).printValue()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:848 +0x27dc

  fmt.(*pp).printArg()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:682 +0x1b1

  fmt.(*pp).doPrintf()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:998 +0x1cad

  fmt.Sprintf()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:196 +0x77

  fmt.Errorf()

      /Users/mschoch/Documents/research/gosrc/src/fmt/print.go:205 +0x67

  github.com/couchbase/cbft.bleveIndexTargets.func1()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:1467 +0x502

  github.com/couchbase/cbgt.ConsistencyWaitGroup()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/pindex_consistency.go:130 +0x15e

  github.com/couchbase/cbft.bleveIndexTargets()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:1478 +0xff5

  github.com/couchbase/cbft.bleveIndexAlias()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:1349 +0x100

  github.com/couchbase/cbft.QueryBleve()

      /Users/mschoch/go/src/github.com/couchbase/cbft/pindex_bleve.go:531 +0xb48

  github.com/couchbase/cbgt/rest.(*QueryHandler).ServeHTTP()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/rest/rest_index.go:275 +0x4cb

  github.com/couchbase/cbgt/rest.(*HandlerWithRESTMeta).ServeHTTP()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/rest/rest.go:180 +0x16d

  github.com/couchbase/cbft.(*AuthVersionHandler).ServeHTTP()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest.go:147 +0x1c6

  github.com/gorilla/mux.(*Router).ServeHTTP()

      /Users/mschoch/go/src/github.com/gorilla/mux/mux.go:99 +0x358

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback.func7.1()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1747 +0x4a0

Previous write at 0x00c4201422f0 by goroutine 16:

  github.com/couchbase/cbgt.(*PIndex).Close()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/pindex.go:60 +0x89

  github.com/couchbase/cbgt.(*Manager).stopPIndex()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/manager_janitor.go:468 +0x2d9

  github.com/couchbase/cbgt.(*Manager).JanitorLoop()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/manager_janitor.go:101 +0x79a

Goroutine 48 (running) created at:

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback.func7()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1749 +0xbc

  github.com/couchbase/cbft.testRESTHandlers()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:142 +0xa0e

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1799 +0x2a2c

  github.com/couchbase/cbft.TestHandlersWithOnePartitionPrimaryFeedRollbackMoss()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1562 +0x2f7

  testing.tRunner()

      /Users/mschoch/Documents/research/gosrc/src/testing/testing.go:657 +0x107

Goroutine 16 (running) created at:

  github.com/couchbase/cbgt.(*Manager).Start()

      /Users/mschoch/go/src/github.com/couchbase/cbgt/manager.go:239 +0x23e

  github.com/couchbase/cbft.testHandlersWithOnePartitionPrimaryFeedRollback()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1577 +0x398

  github.com/couchbase/cbft.TestHandlersWithOnePartitionPrimaryFeedRollbackMoss()

      /Users/mschoch/go/src/github.com/couchbase/cbft/rest_test.go:1562 +0x2f7

  testing.tRunner()

      /Users/mschoch/Documents/research/gosrc/src/testing/testing.go:657 +0x107

==================

2017/04/02 12:46:12 rest: error code: 400, msg: rest_index: Query, indexName: idx0, requestBody: {"size":10,"query":{"query":"boof"},"ctl":{"consistency":{"level":"at_plus","vectors":{"idx0":{"0":11}}}}}, req: &http.Request{Method:"POST", URL:(*url.URL)(0xc420286100), Proto:"", ProtoMajor:0, ProtoMinor:0, Header:http.Header(nil), Body:ioutil.nopCloser{Reader:(*bytes.Buffer)(0xc420096f50)}, GetBody:(func() (io.ReadCloser, error))(nil), ContentLength:0, TransferEncoding:[]string(nil), Close:false, Host:"", Form:url.Values{}, PostForm:url.Values{}, MultipartForm:(*multipart.Form)(nil), Trailer:http.Header(nil), RemoteAddr:"", RequestURI:"", TLS:(*tls.ConnectionState)(nil), Cancel:(<-chan struct {})(nil), Response:(*http.Response)(nil), ctx:context.Context(nil)}, err: bleve: bleveIndexTargets, nil bindex, localPIndex: &cbgt.PIndex{Name:"idx0_89fd127dbb52bac1_f4dbdf21", UUID:"2d4ce95ecce8fc82", IndexType:"fulltext-index", IndexName:"idx0", IndexUUID:"89fd127dbb52bac1", IndexParams:"{}", SourceType:"primary", SourceName:"", SourceUUID:"", SourceParams:"{\"numPartitions\":1}", SourcePartitions:"0", Path:"tmp/test603797474/idx0_89fd127dbb52bac1_f4dbdf21.pindex", Impl:(*bleve.indexImpl)(0xc4202841c0), Dest:(*cbgt.DestForwarder)(0xc42044e200), sourcePartitionsMap:map[string]bool{"0":true}, m:sync.Mutex{state:0, sema:0x0}, closed:true}

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: cfg changed, key: planPIndexes

2017/04/02 12:46:12 janitor: pindexes to remove: 0

2017/04/02 12:46:12 janitor: pindexes to add: 1

2017/04/02 12:46:12   &{Name:idx0_89fd127dbb52bac1_f4dbdf21 UUID:225ba885b2ce7250 IndexType:fulltext-index IndexName:idx0 IndexUUID:89fd127dbb52bac1 IndexParams:{} SourceType:primary SourceName: SourceUUID: SourceParams:{"numPartitions":1} SourcePartitions:0 Nodes:map[144dc592f29fa5fe:0xc42012c1b0]}

2017/04/02 12:46:12 janitor: adding pindex: idx0_89fd127dbb52bac1_f4dbdf21

2017/04/02 12:46:12 janitor: feeds to remove: 0

2017/04/02 12:46:12 janitor: feeds to add: 1

2017/04/02 12:46:12   idx0_89fd127dbb52bac1

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: the plans have changed

2017/04/02 12:46:12 janitor: pindexes to remove: 0

2017/04/02 12:46:12 janitor: pindexes to add: 0

2017/04/02 12:46:12 janitor: feeds to remove: 0

2017/04/02 12:46:12 janitor: feeds to add: 0

2017/04/02 12:46:12 planner: awakes, op: kick, msg: restart-pindex

2017/04/02 12:46:12 planner: once, reason: restart-pindex

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: after-rollback

2017/04/02 12:46:12 janitor: pindexes to remove: 0

2017/04/02 12:46:12 janitor: pindexes to add: 0

2017/04/02 12:46:12 janitor: feeds to remove: 0

2017/04/02 12:46:12 janitor: feeds to add: 0

2017/04/02 12:46:12 janitor: awakes, op: kick, msg: cfg changed, key: planPIndexes

--- FAIL: TestHandlersWithOnePartitionPrimaryFeedRollbackMoss (0.10s)

testing.go:610: race detected during execution of test

FAIL

exit status 1

FAIL	github.com/couchbase/cbft	0.141s

Attachments

Issue Links

relates to

MB-22090 [FTS] Partial Rollback : Querying fails while rollback is in progress

Closed

Gerrit Reviews

- Issue Only
- Show All Reviews
- Show Open Reviews
- Show All Issues
- Show Open Issues

No reviews matched the request. Check your Options in the drop-down menu of this sections header.

Activity

People

Assignee:: Marty Schoch [X] (Inactive)

Reporter:: Marty Schoch [X] (Inactive)

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 02/Apr/17 9:47 AM

Updated:: 02/Apr/17 12:13 PM

Resolved:: 02/Apr/17 11:14 AM

Gerrit Reviews

There are no open Gerrit changes

Show There is 1 closed Gerrit change

Hide There is 1 closed Gerrit change

MB-23674 - do not print *cbgt.PIndex with %#v format without lock: Gerrit Review:

[FTS] race detected in cbft

Details

Description

Attachments

Issue Links

Gerrit Reviews

Activity

People

Dates

Gerrit Reviews

PagerDuty