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

concurrent map writes in dsfs.ComputeFieldsFile #1874

Open
b5 opened this issue Aug 11, 2021 · 1 comment
Open

concurrent map writes in dsfs.ComputeFieldsFile #1874

b5 opened this issue Aug 11, 2021 · 1 comment
Labels
base bug code that is not behaving as expected

Comments

@b5
Copy link
Member

b5 commented Aug 11, 2021

I've seen this error maybe 1 in 20 runs of the dsfs test suite:

fatal error: concurrent map writes
fatal error: concurrent map writes

goroutine 236 [running]:
runtime.throw(0x5729b38, 0x15)
/usr/local/Cellar/go/1.16.6/libexec/src/runtime/panic.go:1117 +0x72 fp=0xc0008f9c80 sp=0xc0008f9c50 pc=0x403ceb2
runtime.mapassign_faststr(0x539f9c0, 0xc00215ea80, 0x5726f6d, 0x14, 0x59ab8a98ff686)
/usr/local/Cellar/go/1.16.6/libexec/src/runtime/map_faststr.go:291 +0x3d8 fp=0xc0008f9ce8 sp=0xc0008f9c80 pc=0x40194f8
github.com/qri-io/qri/base/dsfs.TestDatasetSaveEvents.func1(0x5aa3700, 0xc002162d00, 0x5726f6d, 0x14, 0x169a496307257588, 0x0, 0x0, 0x0, 0x0, 0x5530460, ...)
/Users/b5/qri/qri/base/dsfs/write_test.go:248 +0x4a fp=0xc0008f9d20 sp=0xc0008f9ce8 pc=0x51ee5ca
github.com/qri-io/qri/event.(*bus).publish(0xc0030908c0, 0x5aa3700, 0xc002162d00, 0x5726f6d, 0x14, 0x0, 0x0, 0x5530460, 0xc000b7e060, 0x0, ...)
/Users/b5/qri/qri/event/event.go:176 +0x3d4 fp=0xc0008f9e78 sp=0xc0008f9d20 pc=0x5181694
github.com/qri-io/qri/event.(*bus).Publish(0xc0030908c0, 0x5aa3700, 0xc002162d00, 0x5726f6d, 0x14, 0x5530460, 0xc000b7e060, 0xc002138958, 0xc002142fc0)
/Users/b5/qri/qri/event/event.go:145 +0x7f fp=0xc0008f9ee0 sp=0xc0008f9e78 pc=0x51811bf
github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).flushBatch.func1(0xc002164d80, 0x5aa3700, 0xc002162d00)
/Users/b5/qri/qri/base/dsfs/compute_fields.go:363 +0x16f fp=0xc0008f9fc8 sp=0xc0008f9ee0 pc=0x51eac2f
runtime.goexit()
/usr/local/Cellar/go/1.16.6/libexec/src/runtime/asm_amd64.s:1371 +0x1 fp=0xc0008f9fd0 sp=0xc0008f9fc8 pc=0x4078301
created by github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).flushBatch
/Users/b5/qri/qri/base/dsfs/compute_fields.go:361 +0x639

goroutine 1 [chan receive]:
testing.(*T).Run(0xc000f11200, 0x5729637, 0x15, 0x58c6b40, 0x409cc01)
/usr/local/Cellar/go/1.16.6/libexec/src/testing/testing.go:1239 +0x2da
testing.runTests.func1(0xc000102600)
/usr/local/Cellar/go/1.16.6/libexec/src/testing/testing.go:1511 +0x78
testing.tRunner(0xc000102600, 0xc0008bfde0)
/usr/local/Cellar/go/1.16.6/libexec/src/testing/testing.go:1193 +0xef
testing.runTests(0xc000128c30, 0x67acea0, 0xc, 0xc, 0xc03d18d3f43b46e0, 0x8bb52f0a94, 0x67d95e0, 0x565c1f2)
/usr/local/Cellar/go/1.16.6/libexec/src/testing/testing.go:1509 +0x2fe
testing.(*M).Run(0xc000344780, 0x0)
/usr/local/Cellar/go/1.16.6/libexec/src/testing/testing.go:1417 +0x1eb
main.main()
_testmain.go:71 +0x138

goroutine 6 [select]:
github.com/ipfs/go-log/writer.(*MirrorWriter).logRoutine(0xc0000a5260)
/Users/b5/go/pkg/mod/github.com/ipfs/go-log@v1.0.5/writer/writer.go:71 +0x106
created by github.com/ipfs/go-log/writer.NewMirrorWriter
/Users/b5/go/pkg/mod/github.com/ipfs/go-log@v1.0.5/writer/writer.go:36 +0xb9

goroutine 36 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc000344480)
/Users/b5/go/pkg/mod/go.opencensus.io@v0.23.0/stats/view/worker.go:276 +0xcd
created by go.opencensus.io/stats/view.init.0
/Users/b5/go/pkg/mod/go.opencensus.io@v0.23.0/stats/view/worker.go:34 +0x68

goroutine 76 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc000163520)
/Users/b5/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db_state.go:110 +0x174
created by github.com/syndtr/goleveldb/leveldb.openDB
/Users/b5/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:143 +0x44b

goroutine 230 [runnable]:
math/big.nat.montgomery(0xc002169c20, 0x10, 0x24, 0xc002c9fb80, 0x10, 0x26, 0xc002c9fb80, 0x10, 0x26, 0xc0003e8420, ...)
/usr/local/Cellar/go/1.16.6/libexec/src/math/big/nat.go:213 +0x50d
math/big.nat.expNNMontgomery(0xc002169c20, 0x10, 0x24, 0xc002c9fa40, 0x10, 0x25, 0xc000178a00, 0x10, 0x25, 0xc0003e8420, ...)
/usr/local/Cellar/go/1.16.6/libexec/src/math/big/nat.go:1447 +0x7c5
math/big.nat.expNN(0xc002169c20, 0x20, 0x24, 0xc0002e9440, 0x20, 0x44, 0xc000178a00, 0x10, 0x25, 0xc0003e8420, ...)
/usr/local/Cellar/go/1.16.6/libexec/src/math/big/nat.go:1262 +0xa06
math/big.(*Int).Exp(0xc0018b7640, 0xc001c4b4d8, 0xc000493120, 0xc000493000, 0xc001c4b4f8)
/usr/local/Cellar/go/1.16.6/libexec/src/math/big/int.go:509 +0x1a5
crypto/rsa.decrypt(0x5a74500, 0xc0000a4210, 0xc00010fc20, 0xc001c4b4d8, 0xc001c4b5c8, 0x41b64a6, 0x531bc60)
/usr/local/Cellar/go/1.16.6/libexec/src/crypto/rsa/rsa.go:535 +0x12c
crypto/rsa.decryptAndCheck(0x5a74500, 0xc0000a4210, 0xc00010fc20, 0xc001c4b658, 0x100, 0x100, 0xc002169200)
/usr/local/Cellar/go/1.16.6/libexec/src/crypto/rsa/rsa.go:570 +0x53
crypto/rsa.SignPKCS1v15(0x5a74500, 0xc0000a4210, 0xc00010fc20, 0x5, 0xc001c4b6e8, 0x20, 0x20, 0xc00215eb10, 0xc0000d6500, 0x6, ...)
/usr/local/Cellar/go/1.16.6/libexec/src/crypto/rsa/pkcs1v15.go:253 +0x286
github.com/libp2p/go-libp2p-core/crypto.(*RsaPrivateKey).Sign(0xc00010fc20, 0xc0018ea540, 0xbc, 0xc0, 0x9, 0xc00215eb10, 0xc000122400, 0x0, 0x5649500)
/Users/b5/go/pkg/mod/github.com/libp2p/go-libp2p-core@v0.8.5/crypto/rsa_go.go:88 +0xbe
github.com/qri-io/qri/base/dsfs.commitFileAddFunc.func1(0x5aa8680, 0xc00215e9f0, 0x75c4138, 0xc00215e9f0, 0x0, 0xc000122400, 0xc00215eb10, 0xc0001ac770, 0x5a74880, 0xc00073d090)
/Users/b5/qri/qri/base/dsfs/commit.go:72 +0x835
github.com/qri-io/qri/base/dsfs.WriteDataset(0x5aa3700, 0xc002162d00, 0x5aa8680, 0xc00215e9f0, 0x5aa8680, 0xc00215e9f0, 0x0, 0xc000122400, 0xea3ea40, 0xc0030908c0, ...)
/Users/b5/qri/qri/base/dsfs/write.go:221 +0x52c
github.com/qri-io/qri/base/dsfs.CreateDataset(0x5aa3700, 0xc002162d00, 0x5aa8680, 0xc00215e9f0, 0x5aa8680, 0xc00215e9f0, 0xea3ea40, 0xc0030908c0, 0xc000122400, 0x0, ...)
/Users/b5/qri/qri/base/dsfs/write.go:128 +0x658
github.com/qri-io/qri/base/dsfs.TestDatasetSaveEvents(0xc000f11200)
/Users/b5/qri/qri/base/dsfs/write_test.go:264 +0x578
testing.tRunner(0xc000f11200, 0x58c6b40)
/usr/local/Cellar/go/1.16.6/libexec/src/testing/testing.go:1193 +0xef
created by testing.(*T).Run
/usr/local/Cellar/go/1.16.6/libexec/src/testing/testing.go:1238 +0x2b3

goroutine 54 [chan receive]:
github.com/klauspost/compress/zstd.(*blockDec).startDecoder(0xc0001256c0)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:212 +0x149
created by github.com/klauspost/compress/zstd.newBlockDec
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:118 +0x173

goroutine 55 [chan receive]:
github.com/klauspost/compress/zstd.(*blockDec).startDecoder(0xc000125790)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:212 +0x149
created by github.com/klauspost/compress/zstd.newBlockDec
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:118 +0x173

goroutine 56 [chan receive]:
github.com/klauspost/compress/zstd.(*blockDec).startDecoder(0xc000125860)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:212 +0x149
created by github.com/klauspost/compress/zstd.newBlockDec
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:118 +0x173

goroutine 57 [chan receive]:
github.com/klauspost/compress/zstd.(*blockDec).startDecoder(0xc000125930)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:212 +0x149
created by github.com/klauspost/compress/zstd.newBlockDec
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/blockdec.go:118 +0x173

goroutine 58 [select]:
io.(*pipe).Read(0xc000a10b40, 0xc00000e208, 0x1, 0x8, 0x1, 0xc000a72a58, 0x401da73)
/usr/local/Cellar/go/1.16.6/libexec/src/io/pipe.go:57 +0xcb
io.(*PipeReader).Read(0xc0002287d0, 0xc00000e208, 0x1, 0x8, 0x7700dd8, 0x3200000000000000, 0x0)
/usr/local/Cellar/go/1.16.6/libexec/src/io/pipe.go:134 +0x4c
io.ReadAtLeast(0x5a76920, 0xc0002287d0, 0xc00000e208, 0x1, 0x8, 0x1, 0x401a15b, 0xc00022f2a0, 0x20)
/usr/local/Cellar/go/1.16.6/libexec/src/io/io.go:328 +0x87
io.ReadFull(...)
/usr/local/Cellar/go/1.16.6/libexec/src/io/io.go:347
github.com/klauspost/compress/zstd.(*readerWrapper).readSmall(0xc00000e1f8, 0x1, 0x5451120, 0x1, 0x0, 0x6f72328, 0x10)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/bytebuf.go:88 +0x6d
github.com/klauspost/compress/zstd.(*frameDec).reset(0xc0008c6000, 0x5aa3ea8, 0xc00000e1f8, 0x0, 0x0)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/framedec.go:85 +0x71
github.com/klauspost/compress/zstd.(*Decoder).startStreamDecoder(0xc000133cc0, 0xc000759560)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/decoder.go:492 +0x3de
created by github.com/klauspost/compress/zstd.(*Decoder).Reset
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/decoder.go:202 +0x2ff

goroutine 44 [chan receive]:
github.com/klauspost/compress/zstd.(*Decoder).nextBlock(0xc000133cc0, 0x1, 0x0)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/decoder.go:383 +0x72
github.com/klauspost/compress/zstd.(*Decoder).Read(0xc000133cc0, 0xc000842000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/Users/b5/go/pkg/mod/github.com/klauspost/compress@v1.13.0/zstd/decoder.go:132 +0x117
bufio.(*Reader).fill(0xc0007595c0)
/usr/local/Cellar/go/1.16.6/libexec/src/bufio/bufio.go:101 +0x108
bufio.(*Reader).ReadSlice(0xc0007595c0, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.16.6/libexec/src/bufio/bufio.go:360 +0x3d
bufio.(*Reader).collectFragments(0xc0007595c0, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/usr/local/Cellar/go/1.16.6/libexec/src/bufio/bufio.go:435 +0x7a
bufio.(*Reader).ReadBytes(0xc0007595c0, 0xa, 0x1000000000000, 0x0, 0x0, 0x0, 0x0)
/usr/local/Cellar/go/1.16.6/libexec/src/bufio/bufio.go:463 +0x4c
github.com/qri-io/dataset/dsio.(*NDJSONReader).ReadEntry(0xc00076b920, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/Users/b5/go/pkg/mod/github.com/qri-io/dataset@v0.3.1-0.20210805145914-7be32a154c92/dsio/ndjson.go:59 +0x68
github.com/qri-io/dataset/dsio.EachEntry(0x5a9a2d8, 0xc00076b920, 0xc000a73e90, 0x0, 0x0)
/Users/b5/go/pkg/mod/github.com/qri-io/dataset@v0.3.1-0.20210805145914-7be32a154c92/dsio/entry.go:28 +0x7d
github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).handleRows.func2(0x5a9a2d8, 0xc00076b920, 0xc00075adf0, 0xc00075ade8, 0xc000344880, 0x5aa3738, 0xc0000460d8, 0xc000010748, 0xc0000cdf40, 0xc000759680, ...)
/Users/b5/qri/qri/base/dsfs/compute_fields.go:232 +0x13d
created by github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).handleRows
/Users/b5/qri/qri/base/dsfs/compute_fields.go:231 +0x710

goroutine 29 [select]:
github.com/syndtr/goleveldb/leveldb.(*DB).mpoolDrain(0xc0000a8340)
/Users/b5/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db_state.go:110 +0x174
created by github.com/syndtr/goleveldb/leveldb.openDB
/Users/b5/go/pkg/mod/github.com/syndtr/goleveldb@v1.0.0/leveldb/db.go:143 +0x44b

goroutine 234 [running]:
goroutine running on other thread; stack unavailable
created by github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).handleRows
/Users/b5/qri/qri/base/dsfs/compute_fields.go:214 +0x758

goroutine 231 [chan receive]:
github.com/qri-io/qri/event.NewBus.func1(0x5aa3700, 0xc002162d00, 0xc0030908c0)
/Users/b5/qri/qri/event/event.go:133 +0x4c
created by github.com/qri-io/qri/event.NewBus
/Users/b5/qri/qri/event/event.go:132 +0xcb

goroutine 234 [running]:
runtime.throw(0x5729b38, 0x15)
/usr/local/Cellar/go/1.16.6/libexec/src/runtime/panic.go:1117 +0x72 fp=0xc0008ffc80 sp=0xc0008ffc50 pc=0x403ceb2
runtime.mapassign_faststr(0x539f9c0, 0xc00215ea80, 0x5726f6d, 0x14, 0x59ab8a98ff684)
/usr/local/Cellar/go/1.16.6/libexec/src/runtime/map_faststr.go:291 +0x3d8 fp=0xc0008ffce8 sp=0xc0008ffc80 pc=0x40194f8
github.com/qri-io/qri/base/dsfs.TestDatasetSaveEvents.func1(0x5aa3700, 0xc002162d00, 0x5726f6d, 0x14, 0x169a496307257588, 0x0, 0x0, 0x0, 0x0, 0x5530460, ...)
/Users/b5/qri/qri/base/dsfs/write_test.go:248 +0x4a fp=0xc0008ffd20 sp=0xc0008ffce8 pc=0x51ee5ca
github.com/qri-io/qri/event.(*bus).publish(0xc0030908c0, 0x5aa3700, 0xc002162d00, 0x5726f6d, 0x14, 0x0, 0x0, 0x5530460, 0xc001902180, 0x0, ...)
/Users/b5/qri/qri/event/event.go:176 +0x3d4 fp=0xc0008ffe78 sp=0xc0008ffd20 pc=0x5181694
github.com/qri-io/qri/event.(*bus).Publish(0xc0030908c0, 0x5aa3700, 0xc002162d00, 0x5726f6d, 0x14, 0x5530460, 0xc001902180, 0xc002138958, 0x1)
/Users/b5/qri/qri/event/event.go:145 +0x7f fp=0xc0008ffee0 sp=0xc0008ffe78 pc=0x51811bf
github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).handleRows.func1(0xc002164d80, 0x5aa3700, 0xc002162d00)
/Users/b5/qri/qri/base/dsfs/compute_fields.go:219 +0x17b fp=0xc0008fffc8 sp=0xc0008ffee0 pc=0x51e94fb
runtime.goexit()
/usr/local/Cellar/go/1.16.6/libexec/src/runtime/asm_amd64.s:1371 +0x1 fp=0xc0008fffd0 sp=0xc0008fffc8 pc=0x4078301
created by github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).handleRows

@b5 b5 added bug code that is not behaving as expected base labels Aug 11, 2021
@ramfox
Copy link
Member

ramfox commented Aug 11, 2021

Getting a race condition with two different patterns for tests relying on the save path, both touching dsfs

1:

github.com/qri-io/dataset.(*Dataset).DropTransientValues()
      /Users/ramfox/go/pkg/mod/github.com/qri-io/dataset@v0.3.1-0.20210805145914-7be32a154c92/dataset.go:244 +0x9c4
  github.com/qri-io/qri/base/dsfs.commitFileAddFunc.func1()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/commit.go:69 +0x905
  github.com/qri-io/qri/base/dsfs.WriteDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/write.go:221 +0x524
  github.com/qri-io/qri/base/dsfs.CreateDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/write.go:128 +0x637
  github.com/qri-io/qri/base.CreateDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/save.go:149 +0x577
  github.com/qri-io/qri/base.SaveDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/save.go:111 +0x5b7
  github.com/qri-io/qri/lib.datasetImpl.Save()

2:

github.com/qri-io/dataset/dsio.(*TrackedReader).Read()
      /Users/ramfox/go/pkg/mod/github.com/qri-io/dataset@v0.3.1-0.20210805145914-7be32a154c92/dsio/tracked_reader.go:19 +0xef
  github.com/qri-io/qri/base/dsfs.(*computeFieldsFile).Read()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/compute_fields.go:133 +0x2f
  github.com/qri-io/qri/base/dsfs.memfile.Read()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/file.go:129 +0x9c
  github.com/qri-io/qri/base/dsfs.(*memfile).Read()
      <autogenerated>:1 +0x2e
  io.ReadAll()
      /usr/local/go/src/io/io.go:633 +0x131
  io/ioutil.ReadAll()
      /usr/local/go/src/io/ioutil/ioutil.go:27 +0xcd
  github.com/qri-io/qfs.(*MemFS).PutFile()
      /Users/ramfox/go/pkg/mod/github.com/qri-io/qfs@v0.6.1-0.20210809192005-052457575e43/mem.go:387 +0x8c
  github.com/qri-io/qri/base/dsfs.writePackageFile()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/write.go:518 +0xbc
  github.com/qri-io/qri/base/dsfs.bodyFileFunc.func1()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/write.go:270 +0x3be
  github.com/qri-io/qri/base/dsfs.WriteDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/write.go:221 +0x524
  github.com/qri-io/qri/base/dsfs.CreateDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/dsfs/write.go:128 +0x637
  github.com/qri-io/qri/base.CreateDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/save.go:149 +0x577
  github.com/qri-io/qri/base.SaveDataset()
      /Users/ramfox/go/src/github.com/qri-io/qri/base/save.go:111 +0x5b7
  github.com/qri-io/qri/lib.datasetImpl.Save()

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
base bug code that is not behaving as expected
Projects
None yet
Development

No branches or pull requests

2 participants