error: concurrent map iteration and map write #226

wolfstudy · 2018-12-17T08:08:58Z

Smartphone (please complete the following information):

OS: mac os
Browser :chrome
Version [new master]

Context

The code is the latest code of the current copernicus. When I use ./copernicus --testnet to start, everything ok. At this time, when I use the exporter of prometheus to get the RPC interface of the copernicus client, the following error occurs:

Current data dir: /Users/xiaolong.ran/Library/Application Support/Bitcoincash/testnet
Profile server listening on localhost:6060

fatal error: concurrent map iteration and map write

For detailed error information, please download this link below：

coper_error.log

when i use go build -race, continue to repeat the above steps and try to reproduce the problem, the error log:

coper_race_error.log

Important logs are as follows：

==================
WARNING: DATA RACE
Read at 0x00c000214b70 by goroutine 429:
  github.com/copernet/copernicus/persist/disk.FlushStateToDisk()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/persist/disk/disk.go:397 +0x85f
  github.com/copernet/copernicus/rpc.handleGetTxoutSetInfo()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcblockchain.go:755 +0x55
  github.com/copernet/copernicus/rpc.(*Server).standardCmdResult()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:217 +0x13b
  github.com/copernet/copernicus/rpc.(*Server).jsonRPCRead()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:378 +0xbdb
  github.com/copernet/copernicus/rpc.(*Server).Start.func1()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:448 +0x212
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:1964 +0x51
  net/http.(*ServeMux).ServeHTTP()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:2361 +0x191
  net/http.serverHandler.ServeHTTP()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:2741 +0xc4
  net/http.(*conn).serve()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:1847 +0x80a

Previous write at 0x00c000214b70 by goroutine 70:
  runtime.mapassign()
      /usr/local/Cellar/go/1.11.2/libexec/src/runtime/map.go:549 +0x0
  github.com/copernet/copernicus/persist.(*PersistGlobal).AddDirtyBlockIndex()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/persist/global.go:56 +0x84
  github.com/copernet/copernicus/model/chain.(*Chain).AddToIndexMap()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/model/chain/chain.go:594 +0x409
  github.com/copernet/copernicus/logic/lblock.AcceptBlockHeader()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/logic/lblock/lblock.go:311 +0x5d7
  github.com/copernet/copernicus/service.ProcessBlockHeader()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/service/blockservice.go:19 +0x135
  github.com/copernet/copernicus/net/syncmanager.(*SyncManager).handleHeadersMsg()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/syncmanager/syncmanager.go:946 +0x52d
  github.com/copernet/copernicus/net/syncmanager.(*SyncManager).messagesHandler()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/syncmanager/syncmanager.go:1308 +0x9da

Goroutine 429 (running) created at:
  net/http.(*Server).Serve()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:2851 +0x4c5
  github.com/copernet/copernicus/rpc.(*Server).Start.func2()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:455 +0xcd

Goroutine 70 (running) created at:
  github.com/copernet/copernicus/net/syncmanager.(*SyncManager).Start()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/syncmanager/syncmanager.go:1544 +0xca
  github.com/copernet/copernicus/net/server.(*Server).cycle()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/server/server.go:2056 +0xc3
==================
==================
WARNING: DATA RACE
Read at 0x00c001a15770 by goroutine 429:
  github.com/copernet/copernicus/persist/disk.FlushStateToDisk()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/persist/disk/disk.go:398 +0x995
  github.com/copernet/copernicus/rpc.handleGetTxoutSetInfo()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcblockchain.go:755 +0x55
  github.com/copernet/copernicus/rpc.(*Server).standardCmdResult()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:217 +0x13b
  github.com/copernet/copernicus/rpc.(*Server).jsonRPCRead()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:378 +0xbdb
  github.com/copernet/copernicus/rpc.(*Server).Start.func1()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:448 +0x212
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:1964 +0x51
  net/http.(*ServeMux).ServeHTTP()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:2361 +0x191
  net/http.serverHandler.ServeHTTP()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:2741 +0xc4
  net/http.(*conn).serve()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:1847 +0x80a
Previous write at 0x00c001a15770 by goroutine 70:
  github.com/copernet/copernicus/persist.(*PersistGlobal).AddDirtyBlockIndex()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/persist/global.go:56 +0x99
  github.com/copernet/copernicus/model/chain.(*Chain).AddToIndexMap()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/model/chain/chain.go:594 +0x409
  github.com/copernet/copernicus/logic/lblock.AcceptBlockHeader()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/logic/lblock/lblock.go:311 +0x5d7
  github.com/copernet/copernicus/service.ProcessBlockHeader()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/service/blockservice.go:19 +0x135
  github.com/copernet/copernicus/net/syncmanager.(*SyncManager).handleHeadersMsg()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/syncmanager/syncmanager.go:946 +0x52d
  github.com/copernet/copernicus/net/syncmanager.(*SyncManager).messagesHandler()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/syncmanager/syncmanager.go:1308 +0x9da

Goroutine 429 (running) created at:
  net/http.(*Server).Serve()
      /usr/local/Cellar/go/1.11.2/libexec/src/net/http/server.go:2851 +0x4c5
  github.com/copernet/copernicus/rpc.(*Server).Start.func2()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/rpc/rpcserver.go:455 +0xcd

Goroutine 70 (running) created at:
  github.com/copernet/copernicus/net/syncmanager.(*SyncManager).Start()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/syncmanager/syncmanager.go:1544 +0xca
  github.com/copernet/copernicus/net/server.(*Server).cycle()
      /Users/xiaolong.ran/go/src/github.com/copernet/copernicus/net/server/server.go:2056 +0xc3
==================
fatal error: concurrent map iteration and map write

the exporter of copernicus is a long connect that repeatedly calls the form of RPC， the error:

2018/12/17 15:47:53.300 [E]  EOF
2018/12/17 15:47:53.301 [E]  EOF
2018/12/17 15:47:53.303 [E]  EOF
2018/12/17 15:47:58.307 [E]  EOF
2018/12/17 15:47:58.309 [E]  EOF
2018/12/17 15:47:58.317 [E]  EOF
2018/12/17 15:47:58.317 [E]  EOF
2018/12/17 15:47:58.320 [E]  EOF

This problem can be repeated over and over again.

The text was updated successfully, but these errors were encountered:

whunmr · 2018-12-18T03:55:56Z

Thanks for the detailed logs and ways to reproduce the issue.

fixing this one now.

whunmr · 2018-12-18T05:29:52Z

reproduced before fix

| => coperctl --notls  -s 127.0.0.1:18334 gettxoutsetinfo
==================
WARNING: DATA RACE
Read at 0x00c0001e98c0 by goroutine 81:
  github.com/copernet/copernicus/persist/disk.FlushStateToDisk()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/persist/disk/disk.go:397 +0xd1b
  github.com/copernet/copernicus/rpc.handleGetTxoutSetInfo()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/rpc/rpcblockchain.go:755 +0x86
  github.com/copernet/copernicus/rpc.(*Server).standardCmdResult()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/rpc/rpcserver.go:217 +0x1f6
  github.com/copernet/copernicus/rpc.(*Server).jsonRPCRead()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/rpc/rpcserver.go:378 +0x1d4a
  github.com/copernet/copernicus/rpc.(*Server).Start.func1()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/rpc/rpcserver.go:448 +0x43e
  net/http.HandlerFunc.ServeHTTP()
      /usr/local/opt/go/libexec/src/net/http/server.go:1964 +0x6f
  net/http.(*ServeMux).ServeHTTP()
      /usr/local/opt/go/libexec/src/net/http/server.go:2361 +0x2cb
  net/http.serverHandler.ServeHTTP()
      /usr/local/opt/go/libexec/src/net/http/server.go:2741 +0x34e
  net/http.(*conn).serve()
      /usr/local/opt/go/libexec/src/net/http/server.go:1847 +0x1f7b

Previous write at 0x00c0001e98c0 by goroutine 76:
  runtime.mapassign()
      /usr/local/opt/go/libexec/src/runtime/map.go:549 +0x0
  github.com/copernet/copernicus/persist.(*PersistGlobal).AddDirtyBlockIndex()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/persist/global.go:56 +0xb2
  github.com/copernet/copernicus/model/chain.(*Chain).AddToIndexMap()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/model/chain/chain.go:594 +0x969
  github.com/copernet/copernicus/logic/lblock.AcceptBlockHeader()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/logic/lblock/lblock.go:311 +0x3d3
  github.com/copernet/copernicus/service.ProcessBlockHeader()
      /Users/bj1809120051/.go/src/github.com/copernet/copernicus/service/blockservice.go:19 +0x29e
  github.com/copernet/copernicus/net/syncmanager.(*SyncManager).handleHeadersMsg()

tests after fix
Tested from clean testnet env, the IBD will 1) get all headers and 2)get historical blocks.

test command:

watch -d -n 5 'coperctl --notls -s 127.0.0.1:18334 gettxoutsetinfo'

test logs:

   Every 5.0s: coperctl --notls -s 127.0.0.1:18334 gettxoutsetinfo                                                                                                       Tue Dec 18 13:27:01 2018
{
  "height": 40323,
  "bestblock": "0000000025e580fdacf8b6f98f59d68333dcbae9e2a918a70eeb544aeac6351f",
  "transactions": 35537,
  "txouts": 35558,
  "bogosize": 4189250,
  "hash_serialized": "18784f0a4c52fc033864d6f2d72c26708df251799fb3af4d76fb07479882bce6",
  "disk_size": 2557176,
  "total_amount": 2016150
}

read and write gPersist.GlobalDirtyBlockIndex in GetTxoutSetInfo will race with chain.AddToIndexMap in normal headers/blocks process

wolfstudy added the help wanted Extra attention is needed label Dec 17, 2018

whunmr added a commit to whunmr/copernicus that referenced this issue Dec 19, 2018

Fix data race in GetTxoutSetInfo for issue copernet#226

24c5ad1

read and write gPersist.GlobalDirtyBlockIndex in GetTxoutSetInfo will race with chain.AddToIndexMap in normal headers/blocks process

whunmr mentioned this issue Dec 19, 2018

Fix data race in GetTxoutSetInfo for issue #226 #228

Merged

whitefen pushed a commit that referenced this issue Dec 19, 2018

Fix data race in GetTxoutSetInfo for issue #226

00e8ef7

read and write gPersist.GlobalDirtyBlockIndex in GetTxoutSetInfo will race with chain.AddToIndexMap in normal headers/blocks process

whunmr closed this as completed Dec 19, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

error: concurrent map iteration and map write #226

error: concurrent map iteration and map write #226

wolfstudy commented Dec 17, 2018 •

edited

Loading

whunmr commented Dec 18, 2018

whunmr commented Dec 18, 2018

error: concurrent map iteration and map write #226

error: concurrent map iteration and map write #226

Comments

wolfstudy commented Dec 17, 2018 • edited Loading

whunmr commented Dec 18, 2018

whunmr commented Dec 18, 2018

wolfstudy commented Dec 17, 2018 •

edited

Loading