search

awesome-flow / flow

Flow is a Golang framework for building complex configurable message relays
MIT License
18 stars 4 forks source link

Concurrent map read and map write in Evio receiver #1

Closed osdrv closed 6 years ago

osdrv commented 6 years ago

System: Darwin XXX Darwin Kernel Version 17.7.0: Thu Jun 21 22:53:14 PDT 2018; root:xnu-4570.71.2~1/RELEASE_X86_64 x86_64

Go version: go1.10.3 darwin/amd64

Stack trace:

INFO[0000] Starting msgrelay version 1
INFO[0000] Initializing the pipeline
INFO[0000] Starting Evio receiver. Listeners: [tcp://:3110]
INFO[0000] Connecting tcp_rcv to meta_parser
INFO[0000] Connecting meta_parser to mpx
INFO[0000] Linking mpx with [tcp_sink_7222 tcp_sink_7223 tcp_sink_7224 tcp_sink_7225 tcp_sink_7226 tcp_sink_7227]
INFO[0000] Setting GOMAXPROCS to 0
INFO[0000] Pipeline initalization is complete
INFO[0000] Pipeline GraphViz diagram (plot using https://www.planttext.com):
digraph G {
    tcp_rcv -> meta_parser
    meta_parser -> mpx
    mpx -> tcp_sink_7222
    mpx -> tcp_sink_7223
    mpx -> tcp_sink_7224
    mpx -> tcp_sink_7225
    mpx -> tcp_sink_7226
    mpx -> tcp_sink_7227
}
INFO[0000] Activating the pipeline
INFO[0000] Pipeline successfully activated
fatal error: concurrent map read and map write

goroutine 38 [running]:
runtime.throw(0x43d7b08, 0x21)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/panic.go:616 +0x81 fp=0xc420050bc0 sp=0xc420050ba0 pc=0x402b9d1
runtime.mapaccess2_faststr(0x436c040, 0xc4205a0f30, 0x43cd4ae, 0x4, 0x1, 0x1)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/hashmap_fast.go:270 +0x461 fp=0xc420050c30 sp=0xc420050bc0 pc=0x400ce81
github.com/whiteboxio/flow/pkg/core.(*Message).IsSync(...)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/core/message.go:83
github.com/whiteboxio/flow/pkg/receiver/evio.New.func3(0x4418120, 0xc42012e120, 0xc420344960, 0x18, 0x20, 0xc420344960, 0x0, 0x20, 0xc420092a00)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/receiver/evio/evio.go:99 +0x5d4 fp=0xc420050df0 sp=0xc420050c30 pc=0x42ea664
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.loopRead(0xc4201d2000, 0xc42015e400, 0xc42012e120, 0xc42012e1f8, 0x0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:408 +0x2e0 fp=0xc420050eb0 sp=0xc420050df0 pc=0x42e7f70
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.loopRun.func2(0x13, 0x0, 0x0, 0x0, 0xc420050f78)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:232 +0xe6 fp=0xc420050f00 sp=0xc420050eb0 pc=0x42e9256
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal.(*Poll).Wait(0xc42015e3c0, 0xc420051fa8, 0xc4201d2000, 0x0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal/internal_bsd.go:72 +0xad fp=0xc420051f88 sp=0xc420050f00 pc=0x42e15bd
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.loopRun(0xc4201d2000, 0xc42015e400)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:217 +0x93 fp=0xc420051fd0 sp=0xc420051f88 pc=0x42e6813
runtime.goexit()
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc420051fd8 sp=0xc420051fd0 pc=0x4058151
created by github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.serve
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:150 +0x5d3

goroutine 1 [chan receive, 166 minutes]:
main.main()
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/cmd/flowd/main.go:59 +0x4ac

goroutine 19 [syscall, 166 minutes]:
os/signal.signal_recv(0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/sigqueue.go:139 +0xa7
os/signal.loop()
    /usr/local/Cellar/go/1.10.3/libexec/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.0
    /usr/local/Cellar/go/1.10.3/libexec/src/os/signal/signal_unix.go:28 +0x41

goroutine 4 [sleep]:
time.Sleep(0x3b9aca00)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/time.go:102 +0x166
github.com/whiteboxio/flow/pkg/metrics.sendMetrics(0xc420062070, 0x0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/metrics/metrics.go:62 +0x3f
github.com/whiteboxio/flow/pkg/metrics.Initialize.func1(0xc420062070)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/metrics/metrics.go:50 +0x59
created by github.com/whiteboxio/flow/pkg/metrics.Initialize
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/metrics/metrics.go:47 +0x1a6

goroutine 5 [select]:
github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex(0xc4200600c0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:66 +0x1f2
created by github.com/whiteboxio/flow/pkg/link/mpx.NewMPX
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:24 +0x1cc

goroutine 8 [semacquire, 166 minutes]:
sync.runtime_notifyListWait(0xc42015e1d0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/sema.go:510 +0x10b
sync.(*Cond).Wait(0xc42015e1c0)
    /usr/local/Cellar/go/1.10.3/libexec/src/sync/cond.go:56 +0x80
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.(*server).waitForShutdown(0xc4201d2000)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:67 +0x4f
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.serve.func1(0xc4201d2000)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:114 +0x40
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.serve(0xffffffffffffffff, 0x0, 0x0, 0x43e53b8, 0x43e53c0, 0x0, 0x0, 0xc420046090, 0x0, 0xc42015a020, ...)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:152 +0x5fc
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.Serve(0xffffffffffffffff, 0x0, 0x0, 0x43e53b8, 0x43e53c0, 0x0, 0x0, 0xc420046090, 0x0, 0xc4200460a0, ...)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio.go:189 +0x680
github.com/whiteboxio/flow/pkg/receiver/evio.New.func4(0xc4201400a0, 0xc4200460a0, 0x1, 0x1)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/receiver/evio/evio.go:127 +0x86
created by github.com/whiteboxio/flow/pkg/receiver/evio.New
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/receiver/evio/evio.go:126 +0x458

goroutine 13 [chan receive]:
github.com/whiteboxio/flow/pkg/core.(*Connector).ConnectTo.func1(0xc42000c1a0, 0x44189a0, 0xc42000c0c0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/core/components.go:45 +0x74
created by github.com/whiteboxio/flow/pkg/core.(*Connector).ConnectTo
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/core/components.go:44 +0x53

goroutine 14 [chan receive]:
github.com/whiteboxio/flow/pkg/core.(*Connector).ConnectTo.func1(0xc42000c0a0, 0x4418a00, 0xc4200600c0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/core/components.go:45 +0x74
created by github.com/whiteboxio/flow/pkg/core.(*Connector).ConnectTo
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/core/components.go:44 +0x53

goroutine 15 [select, 166 minutes, locked to thread]:
runtime.gopark(0x43e5d08, 0x0, 0x43cda2f, 0x6, 0x18, 0x1)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/proc.go:291 +0x11a
runtime.selectgo(0xc420158750, 0xc4201920c0)
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/select.go:392 +0xe50
runtime.ensureSigM.func1()
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/signal_unix.go:549 +0x1c6
runtime.goexit()
    /usr/local/Cellar/go/1.10.3/libexec/src/runtime/asm_amd64.s:2361 +0x1

goroutine 35 [syscall, 166 minutes]:
syscall.Syscall6(0x16b, 0xc, 0x0, 0x0, 0xc420220f78, 0x80, 0x0, 0x1, 0x0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/asm_darwin_amd64.s:41 +0x5
syscall.kevent(0xc, 0x0, 0x0, 0xc420220f78, 0x80, 0x0, 0x1, 0xc4201d2000, 0xc42015e280)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/zsyscall_darwin_amd64.go:202 +0x9d
syscall.Kevent(0xc, 0xc420170160, 0x0, 0x1, 0xc420220f78, 0x80, 0x80, 0x0, 0x1, 0x0, ...)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/syscall_bsd.go:447 +0x71
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal.(*Poll).Wait(0xc42015e240, 0xc420221fa8, 0xc4201d2000, 0x0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal/internal_bsd.go:60 +0x13c
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.loopRun(0xc4201d2000, 0xc42015e280)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:217 +0x93
created by github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.serve
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:150 +0x5d3

goroutine 36 [syscall, 166 minutes]:
syscall.Syscall6(0x16b, 0x9, 0x0, 0x0, 0xc420056f78, 0x80, 0x0, 0x1, 0x0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/asm_darwin_amd64.s:41 +0x5
syscall.kevent(0x9, 0x0, 0x0, 0xc420056f78, 0x80, 0x0, 0x1, 0xc4201d2000, 0xc42015e300)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/zsyscall_darwin_amd64.go:202 +0x9d
syscall.Kevent(0x9, 0xc420170180, 0x0, 0x1, 0xc420056f78, 0x80, 0x80, 0x0, 0x1, 0x0, ...)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/syscall_bsd.go:447 +0x71
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal.(*Poll).Wait(0xc42015e2c0, 0xc420057fa8, 0xc4201d2000, 0x0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal/internal_bsd.go:60 +0x13c
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.loopRun(0xc4201d2000, 0xc42015e300)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:217 +0x93
created by github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.serve
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:150 +0x5d3

goroutine 37 [syscall, 166 minutes]:
syscall.Syscall6(0x16b, 0xd, 0x0, 0x0, 0xc42021cf78, 0x80, 0x0, 0x1, 0x0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/asm_darwin_amd64.s:41 +0x5
syscall.kevent(0xd, 0x0, 0x0, 0xc42021cf78, 0x80, 0x0, 0x1, 0xc4201d2000, 0xc42015e380)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/zsyscall_darwin_amd64.go:202 +0x9d
syscall.Kevent(0xd, 0xc4201701a0, 0x0, 0x1, 0xc42021cf78, 0x80, 0x80, 0x0, 0x1, 0x0, ...)
    /usr/local/Cellar/go/1.10.3/libexec/src/syscall/syscall_bsd.go:447 +0x71
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal.(*Poll).Wait(0xc42015e340, 0xc42021dfa8, 0xc4201d2000, 0x0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/internal/internal_bsd.go:60 +0x13c
github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.loopRun(0xc4201d2000, 0xc42015e380)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:217 +0x93
created by github.com/whiteboxio/flow/vendor/github.com/tidwall/evio.serve
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/vendor/github.com/tidwall/evio/evio_unix.go:150 +0x5d3

goroutine 205895316 [runnable]:
github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex.func1(0xc42015a000, 0xc4204e4930, 0xc4205cbc69, 0x4418d60, 0xc4200601c0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46
created by github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46 +0xc9

goroutine 205895314 [runnable]:
net.(*conn).SetDeadline(0xc42009c2e8, 0xbed8c6f0120b39b3, 0x910613b6721, 0x45d1460, 0x0, 0x0)
    /usr/local/Cellar/go/1.10.3/libexec/src/net/net.go:228 +0x20a
github.com/whiteboxio/flow/pkg/sink/tcp.(*TCP).Recv(0xc420060180, 0xc42021ae40, 0x0, 0x0)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/sink/tcp/tcp.go:71 +0xf5
github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex.func1(0xc42015a000, 0xc4204e4930, 0xc4205cbc69, 0x4418d60, 0xc420060180)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:48 +0xff
created by github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46 +0xc9

goroutine 205895315 [runnable]:
github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex.func1(0xc42015a000, 0xc4204e4930, 0xc4205cbc69, 0x4418d60, 0xc420060140)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46
created by github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46 +0xc9

goroutine 205895265 [runnable]:
github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex.func1(0xc42015a000, 0xc4204e4930, 0xc4205cbc69, 0x4418d60, 0xc420060100)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46
created by github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46 +0xc9

goroutine 205895264 [runnable]:
github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex.func1(0xc42015a000, 0xc4204e4930, 0xc4205cbc69, 0x4418d60, 0xc420060240)
    /Users/olegs/workspace/golang/src/github.com/whiteboxio/flow/pkg/link/mpx/mpx.go:46
created by github.com/whiteboxio/flow/pkg/link/mpx.(*MPX).multiplex
osdrv commented 6 years ago

The bug happens because of naive message Meta declaration with no concurrency control. The plan is to get it replaced with sync.Map.

osdrv commented 6 years ago

The mentioned above commit helped to eliminate the problem. Closing for now.