Concurrent access error in multiplayer

[Sharpe49]

Log :
INFO[01-19|19:36:26] Train 2C01 arrived on time at station LIVERPOOL STREET module=simulation msgType=2
INFO[01-19|19:36:52] Train 5U53 entered the area 2 minutes late module=simulation msgType=2
fatal error: concurrent map read and map write

goroutine 16 [running]:
runtime.throw(0x888993, 0x21)
C:/Go/src/runtime/panic.go:617 +0x79 fp=0xc00155f4c8 sp=0xc00155f498 pc=0x42ed89
runtime.mapaccess1_faststr(0x7f89c0, 0xc0000a2780, 0xc000238d3c, 0x3, 0x3)
C:/Go/src/runtime/map_faststr.go:21 +0x470 fp=0xc00155f538 sp=0xc00155f4c8 pc=0x4126b0
github.com/ts2/ts2-sim-server/plugins/points.StandardManager.Direction(...)
C:/Users/gniew/Desktop/ts2-sim-server/plugins/points/points.go:35
github.com/ts2/ts2-sim-server/plugins/points.(*StandardManager).Direction(0xc0000805c0, 0xc0003918c0, 0x3)
:1 +0x85 fp=0xc00155f590 sp=0xc00155f538 pc=0x576515
github.com/ts2/ts2-sim-server/simulation.(*PointsItem).Reversed(...)
C:/Users/gniew/Desktop/ts2-sim-server/simulation/track_points.go:145
github.com/ts2/ts2-sim-server/simulation.(*PointsItem).MarshalJSON(0xc0003918c0, 0x86ed20, 0xc0003918c0, 0x3051bd0, 0xc0003918c0, 0xc000391801)
C:/Users/gniew/Desktop/ts2-sim-server/simulation/track_points.go:229 +0x9f fp=0xc00155f9b8 sp=0xc00155f590 pc=0x56349f
encoding/json.marshalerEncoder(0xc000576150, 0x86ed20, 0xc0003918c0, 0x16, 0xc000390100)
C:/Go/src/encoding/json/encode.go:454 +0xcf fp=0xc00155fa38 sp=0xc00155f9b8 pc=0x4fc0ff
encoding/json.(*encodeState).reflectValue(0xc000576150, 0x86ed20, 0xc0003918c0, 0x16, 0xc000390100)
C:/Go/src/encoding/json/encode.go:334 +0x89 fp=0xc00155fa70 sp=0xc00155fa38 pc=0x4fb769
encoding/json.interfaceEncoder(0xc000576150, 0x7f6a40, 0xc0016bf9a0, 0x194, 0x100)
C:/Go/src/encoding/json/encode.go:620 +0xb4 fp=0xc00155fab8 sp=0xc00155fa70 pc=0x4fdad4
encoding/json.structEncoder.encode(0xc00072ad80, 0x2, 0x2, 0xc000576150, 0x81f460, 0xc0016bf990, 0x199, 0x100)
C:/Go/src/encoding/json/encode.go:660 +0x30b fp=0xc00155fb58 sp=0xc00155fab8 pc=0x4fdfdb
encoding/json.structEncoder.encode-fm(0xc000576150, 0x81f460, 0xc0016bf990, 0x199, 0x100)
C:/Go/src/encoding/json/encode.go:631 +0x7d fp=0xc00155fba8 sp=0xc00155fb58 pc=0x50a26d
encoding/json.structEncoder.encode(0xc00072ac60, 0x2, 0x2, 0xc000576150, 0x81f640, 0xc0016bf980, 0x199, 0x4f0100)
C:/Go/src/encoding/json/encode.go:660 +0x30b fp=0xc00155fc48 sp=0xc00155fba8 pc=0x4fdfdb
encoding/json.structEncoder.encode-fm(0xc000576150, 0x81f640, 0xc0016bf980, 0x199, 0xc0016b0100)
C:/Go/src/encoding/json/encode.go:631 +0x7d fp=0xc00155fc98 sp=0xc00155fc48 pc=0x50a26d
encoding/json.ptrEncoder.encode(0xc000862760, 0xc000576150, 0x7c9dc0, 0xc0016bf980, 0x16, 0x7c0100)
C:/Go/src/encoding/json/encode.go:806 +0xb9 fp=0xc00155fce0 sp=0xc00155fc98 pc=0x4ff4b9
encoding/json.ptrEncoder.encode-fm(0xc000576150, 0x7c9dc0, 0xc0016bf980, 0x16, 0xc001550100)
C:/Go/src/encoding/json/encode.go:801 +0x6b fp=0xc00155fd20 sp=0xc00155fce0 pc=0x50a47b
encoding/json.(*encodeState).reflectValue(0xc000576150, 0x7c9dc0, 0xc0016bf980, 0x16, 0xd40100)
C:/Go/src/encoding/json/encode.go:334 +0x89 fp=0xc00155fd58 sp=0xc00155fd20 pc=0x4fb769
encoding/json.(*encodeState).marshal(0xc000576150, 0x7c9dc0, 0xc0016bf980, 0x800100, 0x0, 0x0)
C:/Go/src/encoding/json/encode.go:306 +0xf5 fp=0xc00155fda0 sp=0xc00155fd58 pc=0x4fb205
encoding/json.(*Encoder).Encode(0xc00155fe80, 0x7c9dc0, 0xc0016bf980, 0x2e040d8, 0xc0008483c0)
C:/Go/src/encoding/json/stream.go:200 +0x91 fp=0xc00155fe30 sp=0xc00155fda0 pc=0x507d41
github.com/gorilla/websocket.(*Conn).WriteJSON(0xc0003821a0, 0x7c9dc0, 0xc0016bf980, 0x0, 0x1)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/json.go:28 +0x10e fp=0xc00155fee0 sp=0xc00155fe30 pc=0x72f14e
github.com/ts2/ts2-sim-server/server.(*connection).processWrite(0xc0003821a0, 0xa6e020, 0xc000bd4c80)
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:95 +0x136 fp=0xc00155ffc8 sp=0xc00155fee0 pc=0x77eac6
runtime.goexit()
C:/Go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00155ffd0 sp=0xc00155ffc8 pc=0x4589d1
created by github.com/ts2/ts2-sim-server/server.(*connection).loop
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:59 +0x51f

goroutine 1 [chan receive, 11 minutes]:
main.main()
C:/Users/gniew/Desktop/ts2-sim-server/main.go:124 +0xbd8

goroutine 19 [syscall, 11 minutes]:
os/signal.signal_recv(0x0)
C:/Go/src/runtime/sigqueue.go:139 +0xa3
os/signal.loop()
C:/Go/src/os/signal/signal_unix.go:23 +0x29
created by os/signal.init.0
C:/Go/src/os/signal/signal_unix.go:29 +0x48

goroutine 4 [IO wait, 11 minutes]:
internal/poll.runtime_pollWait(0x304cda0, 0x72, 0xa66f80)
C:/Go/src/runtime/netpoll.go:182 +0x5d
internal/poll.(*pollDesc).wait(0xc0001081c8, 0x72, 0xd10400, 0x0, 0x0)
C:/Go/src/internal/poll/fd_poll_runtime.go:87 +0xa2
internal/poll.(*ioSrv).ExecIO(0xd4af50, 0xc000108018, 0xc00037a0e0, 0x1, 0x0, 0x1c4)
C:/Go/src/internal/poll/fd_windows.go:228 +0x124
internal/poll.(*FD).acceptOne(0xc000108000, 0x1c4, 0xc00030a000, 0x2, 0x2, 0xc000108018, 0xd4e0c0, 0xc0000a9ad0, 0x40c44f, 0x10)
C:/Go/src/internal/poll/fd_windows.go:864 +0xa9
internal/poll.(*FD).Accept(0xc000108000, 0xc00010e060, 0x0, 0x0, 0x0, 0x0, 0xc000000000, 0x0, 0x0, 0x0, ...)
C:/Go/src/internal/poll/fd_windows.go:898 +0x148
net.(*netFD).accept(0xc000108000, 0xc000036a70, 0xc000036a00, 0x40bb93)
C:/Go/src/net/fd_windows.go:193 +0x81
net.(*TCPListener).accept(0xc00091c018, 0xc0000a9c90, 0x4f64ee8e, 0x3d6a964b8d76a9b9)
C:/Go/src/net/tcpsock_posix.go:139 +0x39
net.(*TCPListener).AcceptTCP(0xc00091c018, 0xc0002f6230, 0x4be3fd, 0x5e249f31)
C:/Go/src/net/tcpsock.go:247 +0x4f
net/http.tcpKeepAliveListener.Accept(0xc00091c018, 0xc0000a9d08, 0x18, 0xc000073080, 0x6f759b)
C:/Go/src/net/http/server.go:3264 +0x36
net/http.(*Server).Serve(0xc0002f61a0, 0xa6d860, 0xc00091c018, 0x0, 0x0)
C:/Go/src/net/http/server.go:2859 +0x234
net/http.(*Server).ListenAndServe(0xc0002f61a0, 0xc0002f61a0, 0xd)
C:/Go/src/net/http/server.go:2797 +0xeb
net/http.ListenAndServe(...)
C:/Go/src/net/http/server.go:3037
github.com/ts2/ts2-sim-server/server.HttpdStart(0x879b6f, 0x7, 0x878283, 0x5)
C:/Users/gniew/Desktop/ts2-sim-server/server/http.go:102 +0x7cc
github.com/ts2/ts2-sim-server/server.Run(0xc000072d80, 0x879b6f, 0x7, 0x878283, 0x5)
C:/Users/gniew/Desktop/ts2-sim-server/server/http.go:63 +0x207
created by main.main
C:/Users/gniew/Desktop/ts2-sim-server/main.go:115 +0x92d

goroutine 6 [runnable]:
github.com/ts2/ts2-sim-server/server.(*Hub).run(0xc000122000, 0xc0000745a0)
C:/Users/gniew/Desktop/ts2-sim-server/server/hub.go:71 +0x212
created by github.com/ts2/ts2-sim-server/server.Run
C:/Users/gniew/Desktop/ts2-sim-server/server/http.go:60 +0xfd

goroutine 8 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x304ccd0, 0x72, 0xa66f80)
C:/Go/src/runtime/netpoll.go:182 +0x5d
internal/poll.(*pollDesc).wait(0xc000108748, 0x72, 0xd10400, 0x0, 0x0)
C:/Go/src/internal/poll/fd_poll_runtime.go:87 +0xa2
internal/poll.(*ioSrv).ExecIO(0xd4af50, 0xc000108598, 0x9f11d8, 0x197, 0x0, 0x0)
C:/Go/src/internal/poll/fd_windows.go:228 +0x124
internal/poll.(*FD).Read(0xc000108580, 0xc000378000, 0x400, 0x400, 0x0, 0x0, 0x0)
C:/Go/src/internal/poll/fd_windows.go:502 +0x26b
net.(*netFD).Read(0xc000108580, 0xc000378000, 0x400, 0x400, 0x83b9a0, 0x0, 0x0)
C:/Go/src/net/fd_windows.go:152 +0x56
net.(*conn).Read(0xc00091c028, 0xc000378000, 0x400, 0x400, 0x0, 0x0, 0x0)
C:/Go/src/net/net.go:177 +0x70
bufio.(*Reader).fill(0xc0007bec60)
C:/Go/src/bufio/bufio.go:100 +0x116
bufio.(*Reader).Peek(0xc0007bec60, 0x2, 0x0, 0x83b9a0, 0xc00149d280, 0xc0000e06c0, 0xc00126ae50)
C:/Go/src/bufio/bufio.go:138 +0x56
github.com/gorilla/websocket.(*Conn).read(0xc000382000, 0x2, 0x4f2631, 0x8, 0xa, 0xc00126ae40, 0x2)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/conn.go:357 +0x47
github.com/gorilla/websocket.(*Conn).advanceFrame(0xc000382000, 0x0, 0x0, 0x30)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/conn.go:787 +0x63
github.com/gorilla/websocket.(*Conn).NextReader(0xc000382000, 0x4534e0, 0xc0000741e0, 0xc000a119b8, 0xc000a119b8, 0x40c44f)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/conn.go:947 +0xa7
github.com/gorilla/websocket.(*Conn).ReadJSON(0xc000382000, 0x7c9d40, 0xc00080c5c0, 0x0, 0x1)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/json.go:50 +0x36
github.com/ts2/ts2-sim-server/server.(*connection).processRead(0xc000382000, 0xa6e020, 0xc000bd43c0)
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:72 +0xac
github.com/ts2/ts2-sim-server/server.(*connection).loop(0xc000382000, 0xa6e020, 0xc000bd4280)
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:60 +0x544
github.com/ts2/ts2-sim-server/server.serveWs(0xa6d420, 0xc000362000, 0xc0002c4100)
C:/Users/gniew/Desktop/ts2-sim-server/server/websocket.go:53 +0x2e4
net/http.HandlerFunc.ServeHTTP(0x9f1070, 0xa6d420, 0xc000362000, 0xc0002c4100)
C:/Go/src/net/http/server.go:1995 +0x4b
net/http.(*ServeMux).ServeHTTP(0xd4d280, 0xa6d420, 0xc000362000, 0xc0002c4100)
C:/Go/src/net/http/server.go:2375 +0x1dd
net/http.serverHandler.ServeHTTP(0xc0002f61a0, 0xa6d420, 0xc000362000, 0xc0002c4100)
C:/Go/src/net/http/server.go:2774 +0xaf
net/http.(*conn).serve(0xc000086000, 0xa6e020, 0xc000bd4000)
C:/Go/src/net/http/server.go:1878 +0x858
created by net/http.(*Server).Serve
C:/Go/src/net/http/server.go:2884 +0x2fb

goroutine 51 [runnable]:
encoding/json.stateBeginValue(0xc000fdf6c0, 0xc000fdf67b, 0x0)
C:/Go/src/encoding/json/scanner.go:176 +0x58e
encoding/json.compact(0xc000306000, 0xc000a18680, 0x182, 0x1a0, 0x1, 0x0, 0xc000920650)
C:/Go/src/encoding/json/indent.go:39 +0x335
encoding/json.marshalerEncoder(0xc000306000, 0x86ed20, 0xc0003918c0, 0x16, 0xc000390100)
C:/Go/src/encoding/json/encode.go:457 +0x1d7
encoding/json.(*encodeState).reflectValue(0xc000306000, 0x86ed20, 0xc0003918c0, 0x16, 0xc000390100)
C:/Go/src/encoding/json/encode.go:334 +0x89
encoding/json.interfaceEncoder(0xc000306000, 0x7f6a40, 0xc0016bf970, 0x194, 0x100)
C:/Go/src/encoding/json/encode.go:620 +0xb4
encoding/json.structEncoder.encode(0xc00072ad80, 0x2, 0x2, 0xc000306000, 0x81f460, 0xc0016bf960, 0x199, 0x100)
C:/Go/src/encoding/json/encode.go:660 +0x30b
encoding/json.structEncoder.encode(0xc00072ac60, 0x2, 0x2, 0xc000306000, 0x81f640, 0xc0016bf950, 0x199, 0x4f0100)
C:/Go/src/encoding/json/encode.go:660 +0x30b
encoding/json.ptrEncoder.encode(0xc000862760, 0xc000306000, 0x7c9dc0, 0xc0016bf950, 0x16, 0x7c0100)
C:/Go/src/encoding/json/encode.go:806 +0xb9
encoding/json.(*encodeState).reflectValue(0xc000306000, 0x7c9dc0, 0xc0016bf950, 0x16, 0xd40100)
C:/Go/src/encoding/json/encode.go:334 +0x89
encoding/json.(*encodeState).marshal(0xc000306000, 0x7c9dc0, 0xc0016bf950, 0x800100, 0x0, 0x0)
C:/Go/src/encoding/json/encode.go:306 +0xf5
encoding/json.(*Encoder).Encode(0xc000503e80, 0x7c9dc0, 0xc0016bf950, 0x2e040d8, 0xc000fe7ce0)
C:/Go/src/encoding/json/stream.go:200 +0x91
github.com/gorilla/websocket.(*Conn).WriteJSON(0xc000382000, 0x7c9dc0, 0xc0016bf950, 0x0, 0x1)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/json.go:28 +0x10e
github.com/ts2/ts2-sim-server/server.(*connection).processWrite(0xc000382000, 0xa6e020, 0xc000bd43c0)
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:95 +0x136
created by github.com/ts2/ts2-sim-server/server.(*connection).loop
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:59 +0x51f

goroutine 45 [IO wait]:
internal/poll.runtime_pollWait(0x304cc00, 0x72, 0xa66f80)
C:/Go/src/runtime/netpoll.go:182 +0x5d
internal/poll.(*pollDesc).wait(0xc000108a08, 0x72, 0xd10400, 0x0, 0x0)
C:/Go/src/internal/poll/fd_poll_runtime.go:87 +0xa2
internal/poll.(*ioSrv).ExecIO(0xd4af50, 0xc000108858, 0x9f11d8, 0x197, 0x0, 0x0)
C:/Go/src/internal/poll/fd_windows.go:228 +0x124
internal/poll.(*FD).Read(0xc000108840, 0xc000378400, 0x400, 0x400, 0x0, 0x0, 0x0)
C:/Go/src/internal/poll/fd_windows.go:502 +0x26b
net.(*netFD).Read(0xc000108840, 0xc000378400, 0x400, 0x400, 0x83b9a0, 0x0, 0x0)
C:/Go/src/net/fd_windows.go:152 +0x56
net.(*conn).Read(0xc000836000, 0xc000378400, 0x400, 0x400, 0x0, 0x0, 0x0)
C:/Go/src/net/net.go:177 +0x70
bufio.(*Reader).fill(0xc000392cc0)
C:/Go/src/bufio/bufio.go:100 +0x116
bufio.(*Reader).Peek(0xc000392cc0, 0x2, 0x0, 0x83b9a0, 0xc00085f980, 0xc0000e06c0, 0xc0008bec38)
C:/Go/src/bufio/bufio.go:138 +0x56
github.com/gorilla/websocket.(*Conn).read(0xc0003821a0, 0x2, 0x4f2631, 0x8, 0xa, 0xc0008bec50, 0x2)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/conn.go:357 +0x47
github.com/gorilla/websocket.(*Conn).advanceFrame(0xc0003821a0, 0x0, 0x0, 0x30)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/conn.go:787 +0x63
github.com/gorilla/websocket.(*Conn).NextReader(0xc0003821a0, 0x4534e0, 0xc0000741e0, 0xc0015639b8, 0xc0015639b8, 0x40c44f)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/conn.go:947 +0xa7
github.com/gorilla/websocket.(*Conn).ReadJSON(0xc0003821a0, 0x7c9d40, 0xc0015f7c00, 0x0, 0x1)
C:/Users/gniew/go/pkg/mod/github.com/gorilla/websocket@v1.4.0/json.go:50 +0x36
github.com/ts2/ts2-sim-server/server.(*connection).processRead(0xc0003821a0, 0xa6e020, 0xc000bd4c80)
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:72 +0xac
github.com/ts2/ts2-sim-server/server.(*connection).loop(0xc0003821a0, 0xa6e020, 0xc000bd4b80)
C:/Users/gniew/Desktop/ts2-sim-server/server/connection.go:60 +0x544
github.com/ts2/ts2-sim-server/server.serveWs(0xa6d420, 0xc0003620e0, 0xc0002c4200)
C:/Users/gniew/Desktop/ts2-sim-server/server/websocket.go:53 +0x2e4
net/http.HandlerFunc.ServeHTTP(0x9f1070, 0xa6d420, 0xc0003620e0, 0xc0002c4200)
C:/Go/src/net/http/server.go:1995 +0x4b
net/http.(*ServeMux).ServeHTTP(0xd4d280, 0xa6d420, 0xc0003620e0, 0xc0002c4200)
C:/Go/src/net/http/server.go:2375 +0x1dd
net/http.serverHandler.ServeHTTP(0xc0002f61a0, 0xa6d420, 0xc0003620e0, 0xc0002c4200)
C:/Go/src/net/http/server.go:2774 +0xaf
net/http.(*conn).serve(0xc0001441e0, 0xa6e020, 0xc000bd49c0)
C:/Go/src/net/http/server.go:1878 +0x858
created by net/http.(*Server).Serve
C:/Go/src/net/http/server.go:2884 +0x2fb

goroutine 49 [select]:
github.com/ts2/ts2-sim-server/simulation.(*Simulation).run(0xc000072d80)
C:/Users/gniew/Desktop/ts2-sim-server/simulation/simulation.go:297 +0x106
created by github.com/ts2/ts2-sim-server/simulation.(*Simulation).Start
C:/Users/gniew/Desktop/ts2-sim-server/simulation/simulation.go:288 +0x7a

goroutine 59 [runnable]:
github.com/ts2/ts2-sim-server/simulation.(*trackStruct).setActiveRoute(0xc0008227e0, 0xc000030c00, 0xa752c0, 0xc000270420)
C:/Users/gniew/Desktop/ts2-sim-server/simulation/track_items.go:369 +0x11f
github.com/ts2/ts2-sim-server/simulation.(*Route).Activate(0xc000030c00, 0xc00090cf00, 0xc00086a350, 0x2)
C:/Users/gniew/Desktop/ts2-sim-server/simulation/routes.go:132 +0x5f3
github.com/ts2/ts2-sim-server/server.(*routeObject).dispatch(0xd680c8, 0xc000122000, 0x29, 0xc0008bec62, 0x5, 0xc0008bec68, 0x8, 0xc000176360, 0x21, 0x30, ...)
C:/Users/gniew/Desktop/ts2-sim-server/server/hub_route.go:83 +0x2d50
github.com/ts2/ts2-sim-server/server.(*Hub).dispatchObject(0xc000122000, 0xc0003821a0)
C:/Users/gniew/Desktop/ts2-sim-server/server/hub.go:177 +0x58d
created by github.com/ts2/ts2-sim-server/server.(*Hub).run
C:/Users/gniew/Desktop/ts2-sim-server/server/hub.go:77 +0x725

[npiganeau]

I've just pushed a fix on master branch for this. Hoping this will help.

[Sharpe49]

Alright, there is no crash, but when the server seems to freeze at a moment. The GUI is responding but not the server. Perhaps a mutex is not unlocked properly.
I also tested it without the patch for the other issue. Same problem.
We should probably do a test session together.

[Sharpe49]

@npiganeau Ok, it is still not fixed.
It went back to the same error of the first message.

[npiganeau]

@Sharpe49 Do you have the stack trace? I suppose it is a different map where we have a concurrent read/write.

[npiganeau]

I removed two other copied mutexes.

Can you test multiplayer-fix branch ? (PR #52 )

[Sharpe49]

Ok, we had a freeze with this version. It happened when a train entered the map.
And some messages were received after the start of the freeze (a train entered the map).

[npiganeau]

@Sharpe49 I'm trying to reproduce with a unit test but I couldn't.

Do you have a way to reproduce the bug ? Or perhaps more information to help find the issue ?