search

trezor / trezord-go

:smiling_imp: Trezor Communication Daemon (written in Go)
GNU Lesser General Public License v3.0
244 stars 146 forks source link

bridge crash #190

Closed mroz22 closed 4 years ago

mroz22 commented 4 years ago

what happend: trezord crashed while working with multiple devices (model One 1.8.3. and model T 2.3.0)

system: Ubuntu 18.04.4 LTS

log attached

log.txt

prusnak commented 4 years ago

Probably related to one of the commits:

tsusanka commented 4 years ago

@mroz22 found this on 3e7fc15125b5eab1fb1783c9162fae6fb268424f which was later rebased and merged into master. So this should happen on master as well.

tsusanka commented 4 years ago

I wasn't able to reproduce the crash, but running with -race I have received a warning which is most likely related:

``` WARNING: DATA RACE Write at 0x00c0000a66c0 by goroutine 23: runtime.mapdelete_faststr() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/runtime/map_faststr.go:297 +0x0 github.com/trezor/trezord-go/core.(*Core).release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:359 +0x1fc github.com/trezor/trezord-go/core.(*Core).Release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:345 +0x138 github.com/trezor/trezord-go/server/api.(*api).release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/api.go:157 +0xef github.com/trezor/trezord-go/server/api.(*api).Release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/api.go:144 +0x64 github.com/trezor/trezord-go/server/api.(*api).Release-fm() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/api.go:143 +0x22 net/http.HandlerFunc.ServeHTTP() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2012 +0x51 github.com/trezor/trezord-go/server/api.(*cors).ServeHTTP() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/cors.go:69 +0x583 github.com/trezor/trezord-go/vendor/github.com/gorilla/mux.(*Router).ServeHTTP() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/vendor/github.com/gorilla/mux/mux.go:159 +0x193 github.com/trezor/trezord-go/vendor/github.com/gorilla/handlers.loggingHandler.ServeHTTP() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/vendor/github.com/gorilla/handlers/handlers.go:69 +0x309 github.com/trezor/trezord-go/vendor/github.com/gorilla/handlers.(*loggingHandler).ServeHTTP() :1 +0xa6 github.com/trezor/trezord-go/server.(*Server).logRequest.func1() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/http.go:82 +0x277 net/http.HandlerFunc.ServeHTTP() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2012 +0x51 net/http.serverHandler.ServeHTTP() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2807 +0xce net/http.(*conn).serve() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:1895 +0x837 Previous read at 0x00c0000a66c0 by goroutine 9: runtime.mapiterinit() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/runtime/map.go:797 +0x0 github.com/trezor/trezord-go/core.(*Core).releaseDisconnected() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:325 +0xb9 github.com/trezor/trezord-go/core.(*Core).Enumerate() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:268 +0x40f github.com/trezor/trezord-go/core.(*Core).backgroundListen() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:187 +0x106 Goroutine 23 (running) created at: net/http.(*Server).Serve() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2933 +0x5b6 net/http.(*Server).ListenAndServe() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2830 +0x102 github.com/trezor/trezord-go/server.(*Server).Run() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/http.go:87 +0x1441 main.main() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/trezord.go:178 +0x1424 Goroutine 9 (running) created at: github.com/trezor/trezord-go/core.New() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:162 +0x1e4 main.main() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/trezord.go:169 +0x12e7 ```
tsusanka commented 4 years ago

I was able to reproduce the warning on 2.0.28 as well.

``` ./trezord-go trezord-go-dev 2020/05/12 09:09:35 trezord v2.0.28 is starting. POST / 127.0.0.1 - - [12/May/2020:09:09:35 +0200] "POST / HTTP/1.1" 200 21 POST /enumerate 127.0.0.1 - - [12/May/2020:09:09:35 +0200] "POST /enumerate HTTP/1.1" 200 186 POST /listen POST /acquire/1/null 127.0.0.1 - - [12/May/2020:09:09:35 +0200] "POST /acquire/1/null HTTP/1.1" 200 16 POST /call/1 127.0.0.1 - - [12/May/2020:09:09:35 +0200] "POST /call/1 HTTP/1.1" 200 340 127.0.0.1 - - [12/May/2020:09:09:35 +0200] "POST /listen HTTP/1.1" 200 185 POST /listen POST /release/1 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /release/1 HTTP/1.1" 200 16 POST /acquire/2/null POST /acquire/1/null 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /acquire/2/null HTTP/1.1" 200 16 POST /call/2 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /acquire/1/null HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /listen HTTP/1.1" 200 184 POST /call/3 POST /listen 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /call/2 HTTP/1.1" 200 260 POST /release/2 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /release/2 HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /call/3 HTTP/1.1" 200 410 POST /call/3 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /listen HTTP/1.1" 200 185 POST /listen 127.0.0.1 - - [12/May/2020:09:09:36 +0200] "POST /call/3 HTTP/1.1" 200 12 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:29 +0200] "POST /call/3 HTTP/1.1" 200 84 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:29 +0200] "POST /call/3 HTTP/1.1" 200 340 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:30 +0200] "POST /call/3 HTTP/1.1" 200 84 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:30 +0200] "POST /call/3 HTTP/1.1" 200 408 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:30 +0200] "POST /call/3 HTTP/1.1" 200 408 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:31 +0200] "POST /call/3 HTTP/1.1" 200 408 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:31 +0200] "POST /call/3 HTTP/1.1" 200 84 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:31 +0200] "POST /call/3 HTTP/1.1" 200 408 POST /call/3 127.0.0.1 - - [12/May/2020:09:10:31 +0200] "POST /call/3 HTTP/1.1" 200 340 POST /release/3 127.0.0.1 - - [12/May/2020:09:10:31 +0200] "POST /release/3 HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:09:37 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/2/null 127.0.0.1 - - [12/May/2020:09:10:37 +0200] "POST /acquire/2/null HTTP/1.1" 200 16 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:37 +0200] "POST /call/4 HTTP/1.1" 200 260 127.0.0.1 - - [12/May/2020:09:10:32 +0200] "POST /listen HTTP/1.1" 200 185 POST /listen POST /call/4 127.0.0.1 - - [12/May/2020:09:10:37 +0200] "POST /call/4 HTTP/1.1" 200 12 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:41 +0200] "POST /call/4 HTTP/1.1" 200 84 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:41 +0200] "POST /call/4 HTTP/1.1" 200 264 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:41 +0200] "POST /call/4 HTTP/1.1" 200 84 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:41 +0200] "POST /call/4 HTTP/1.1" 200 408 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:41 +0200] "POST /call/4 HTTP/1.1" 200 408 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:41 +0200] "POST /call/4 HTTP/1.1" 200 408 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:42 +0200] "POST /call/4 HTTP/1.1" 200 84 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:42 +0200] "POST /call/4 HTTP/1.1" 200 408 POST /call/4 127.0.0.1 - - [12/May/2020:09:10:42 +0200] "POST /call/4 HTTP/1.1" 200 264 POST /release/4 127.0.0.1 - - [12/May/2020:09:10:42 +0200] "POST /release/4 HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:10:37 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/2/null 127.0.0.1 - - [12/May/2020:09:10:48 +0200] "POST /acquire/2/null HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:10:42 +0200] "POST /listen HTTP/1.1" 200 185 POST /call/5 POST /listen 127.0.0.1 - - [12/May/2020:09:10:48 +0200] "POST /call/5 HTTP/1.1" 200 264 POST /call/5 127.0.0.1 - - [12/May/2020:09:10:49 +0200] "POST /call/5 HTTP/1.1" 200 12 POST /call/5 127.0.0.1 - - [12/May/2020:09:10:49 +0200] "POST /call/5 HTTP/1.1" 200 84 POST /call/5 127.0.0.1 - - [12/May/2020:09:10:49 +0200] "POST /call/5 HTTP/1.1" 200 100 POST /call/5 127.0.0.1 - - [12/May/2020:09:10:49 +0200] "POST /call/5 HTTP/1.1" 200 16 POST /call/5 127.0.0.1 - - [12/May/2020:09:10:49 +0200] "POST /call/5 HTTP/1.1" 200 100 POST /call/5 127.0.0.1 - - [12/May/2020:09:10:51 +0200] "POST /call/5 HTTP/1.1" 200 264 POST /release/5 127.0.0.1 - - [12/May/2020:09:10:51 +0200] "POST /release/5 HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:10:48 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/1/null 127.0.0.1 - - [12/May/2020:09:11:05 +0200] "POST /acquire/1/null HTTP/1.1" 200 16 POST /call/6 127.0.0.1 - - [12/May/2020:09:11:05 +0200] "POST /call/6 HTTP/1.1" 200 410 127.0.0.1 - - [12/May/2020:09:10:51 +0200] "POST /listen HTTP/1.1" 200 185 POST /listen POST /call/6 127.0.0.1 - - [12/May/2020:09:11:07 +0200] "POST /call/6 HTTP/1.1" 200 84 POST /call/6 127.0.0.1 - - [12/May/2020:09:11:07 +0200] "POST /call/6 HTTP/1.1" 200 100 POST /call/6 127.0.0.1 - - [12/May/2020:09:11:07 +0200] "POST /call/6 HTTP/1.1" 200 16 POST /call/6 127.0.0.1 - - [12/May/2020:09:11:08 +0200] "POST /call/6 HTTP/1.1" 200 100 POST /call/6 127.0.0.1 - - [12/May/2020:09:11:13 +0200] "POST /call/6 HTTP/1.1" 200 340 POST /release/6 127.0.0.1 - - [12/May/2020:09:11:13 +0200] "POST /release/6 HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:11:05 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/1/null 127.0.0.1 - - [12/May/2020:09:11:19 +0200] "POST /acquire/1/null HTTP/1.1" 200 16 POST /call/7 127.0.0.1 - - [12/May/2020:09:11:14 +0200] "POST /listen HTTP/1.1" 200 185 POST /listen 127.0.0.1 - - [12/May/2020:09:11:19 +0200] "POST /call/7 HTTP/1.1" 200 410 POST /call/7 127.0.0.1 - - [12/May/2020:09:11:21 +0200] "POST /call/7 HTTP/1.1" 200 84 POST /call/7 127.0.0.1 - - [12/May/2020:09:11:21 +0200] "POST /call/7 HTTP/1.1" 200 100 POST /call/7 127.0.0.1 - - [12/May/2020:09:11:21 +0200] "POST /call/7 HTTP/1.1" 200 16 POST /call/7 127.0.0.1 - - [12/May/2020:09:11:22 +0200] "POST /call/7 HTTP/1.1" 200 100 POST /call/7 127.0.0.1 - - [12/May/2020:09:11:27 +0200] "POST /call/7 HTTP/1.1" 200 340 POST /release/7 127.0.0.1 - - [12/May/2020:09:11:27 +0200] "POST /release/7 HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:11:19 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/1/null 127.0.0.1 - - [12/May/2020:09:11:48 +0200] "POST /acquire/1/null HTTP/1.1" 200 16 POST /call/8 127.0.0.1 - - [12/May/2020:09:11:48 +0200] "POST /call/8 HTTP/1.1" 200 410 127.0.0.1 - - [12/May/2020:09:11:27 +0200] "POST /listen HTTP/1.1" 200 185 POST /listen POST /call/8 127.0.0.1 - - [12/May/2020:09:11:50 +0200] "POST /call/8 HTTP/1.1" 200 84 POST /call/8 127.0.0.1 - - [12/May/2020:09:11:50 +0200] "POST /call/8 HTTP/1.1" 200 100 POST /call/8 127.0.0.1 - - [12/May/2020:09:11:50 +0200] "POST /call/8 HTTP/1.1" 200 16 POST /call/8 127.0.0.1 - - [12/May/2020:09:11:51 +0200] "POST /call/8 HTTP/1.1" 200 100 POST /call/8 127.0.0.1 - - [12/May/2020:09:11:54 +0200] "POST /call/8 HTTP/1.1" 200 340 POST /release/8 127.0.0.1 - - [12/May/2020:09:11:54 +0200] "POST /release/8 HTTP/1.1" 200 16 127.0.0.1 - - [12/May/2020:09:11:48 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:11:54 +0200] "POST /listen HTTP/1.1" 200 94 POST /post/8 127.0.0.1 - - [12/May/2020:09:11:57 +0200] "POST /post/8 HTTP/1.1" 400 30 POST /listen 127.0.0.1 - - [12/May/2020:09:11:57 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/3/null 127.0.0.1 - - [12/May/2020:09:12:07 +0200] "POST /acquire/3/null HTTP/1.1" 200 16 POST /call/9 127.0.0.1 - - [12/May/2020:09:12:07 +0200] "POST /call/9 HTTP/1.1" 200 340 127.0.0.1 - - [12/May/2020:09:12:07 +0200] "POST /listen HTTP/1.1" 200 185 POST /listen POST /release/9 127.0.0.1 - - [12/May/2020:09:12:07 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:12:07 +0200] "POST /release/9 HTTP/1.1" 200 16 POST /acquire/3/null 127.0.0.1 - - [12/May/2020:09:12:13 +0200] "POST /acquire/3/null HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:12:07 +0200] "POST /listen HTTP/1.1" 200 186 POST /call/10 POST /listen 127.0.0.1 - - [12/May/2020:09:12:14 +0200] "POST /call/10 HTTP/1.1" 200 410 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:14 +0200] "POST /call/10 HTTP/1.1" 200 12 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:16 +0200] "POST /call/10 HTTP/1.1" 200 84 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:18 +0200] "POST /call/10 HTTP/1.1" 200 340 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:18 +0200] "POST /call/10 HTTP/1.1" 200 84 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:18 +0200] "POST /call/10 HTTP/1.1" 200 408 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:18 +0200] "POST /call/10 HTTP/1.1" 200 408 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:19 +0200] "POST /call/10 HTTP/1.1" 200 408 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:19 +0200] "POST /call/10 HTTP/1.1" 200 84 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:19 +0200] "POST /call/10 HTTP/1.1" 200 408 POST /call/10 127.0.0.1 - - [12/May/2020:09:12:19 +0200] "POST /call/10 HTTP/1.1" 200 340 POST /release/10 127.0.0.1 - - [12/May/2020:09:12:19 +0200] "POST /release/10 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:12:14 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/3/null 127.0.0.1 - - [12/May/2020:09:12:20 +0200] "POST /acquire/3/null HTTP/1.1" 200 17 POST /call/11 127.0.0.1 - - [12/May/2020:09:12:20 +0200] "POST /call/11 HTTP/1.1" 200 410 127.0.0.1 - - [12/May/2020:09:12:20 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /call/11 127.0.0.1 - - [12/May/2020:09:12:20 +0200] "POST /call/11 HTTP/1.1" 200 12 POST /call/11 127.0.0.1 - - [12/May/2020:09:12:26 +0200] "POST /call/11 HTTP/1.1" 200 84 POST /call/11 127.0.0.1 - - [12/May/2020:09:12:27 +0200] "POST /call/11 HTTP/1.1" 200 340 POST /release/11 127.0.0.1 - - [12/May/2020:09:12:27 +0200] "POST /release/11 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:12:20 +0200] "POST /listen HTTP/1.1" 200 94 POST /post/5 127.0.0.1 - - [12/May/2020:09:12:27 +0200] "POST /post/5 HTTP/1.1" 400 30 POST /listen 127.0.0.1 - - [12/May/2020:09:12:27 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/4/null 127.0.0.1 - - [12/May/2020:09:12:32 +0200] "POST /acquire/4/null HTTP/1.1" 200 17 POST /call/12 127.0.0.1 - - [12/May/2020:09:12:32 +0200] "POST /call/12 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:12:32 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /release/12 127.0.0.1 - - [12/May/2020:09:12:32 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:12:32 +0200] "POST /release/12 HTTP/1.1" 200 17 POST /acquire/4/null 127.0.0.1 - - [12/May/2020:09:12:36 +0200] "POST /acquire/4/null HTTP/1.1" 200 17 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:37 +0200] "POST /call/13 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:12:32 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /call/13 127.0.0.1 - - [12/May/2020:09:12:37 +0200] "POST /call/13 HTTP/1.1" 200 12 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:38 +0200] "POST /call/13 HTTP/1.1" 200 84 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:39 +0200] "POST /call/13 HTTP/1.1" 200 264 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:49 +0200] "POST /call/13 HTTP/1.1" 200 84 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:49 +0200] "POST /call/13 HTTP/1.1" 200 100 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:50 +0200] "POST /call/13 HTTP/1.1" 200 16 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:50 +0200] "POST /call/13 HTTP/1.1" 200 100 POST /call/13 127.0.0.1 - - [12/May/2020:09:12:52 +0200] "POST /call/13 HTTP/1.1" 200 264 POST /release/13 127.0.0.1 - - [12/May/2020:09:12:52 +0200] "POST /release/13 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:12:37 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/4/null 127.0.0.1 - - [12/May/2020:09:13:03 +0200] "POST /acquire/4/null HTTP/1.1" 200 17 POST /call/14 127.0.0.1 - - [12/May/2020:09:12:52 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:13:03 +0200] "POST /call/14 HTTP/1.1" 200 264 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:03 +0200] "POST /call/14 HTTP/1.1" 200 12 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:05 +0200] "POST /call/14 HTTP/1.1" 200 84 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:06 +0200] "POST /call/14 HTTP/1.1" 200 264 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:06 +0200] "POST /call/14 HTTP/1.1" 200 84 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:06 +0200] "POST /call/14 HTTP/1.1" 200 408 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /call/14 HTTP/1.1" 200 408 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /call/14 HTTP/1.1" 200 408 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /call/14 HTTP/1.1" 200 84 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /call/14 HTTP/1.1" 200 408 POST /call/14 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /call/14 HTTP/1.1" 200 264 POST /release/14 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /release/14 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:13:03 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/4/null 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /acquire/4/null HTTP/1.1" 200 17 POST /call/15 127.0.0.1 - - [12/May/2020:09:13:08 +0200] "POST /call/15 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:13:07 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /call/15 127.0.0.1 - - [12/May/2020:09:13:08 +0200] "POST /call/15 HTTP/1.1" 200 12 POST /call/15 127.0.0.1 - - [12/May/2020:09:13:14 +0200] "POST /call/15 HTTP/1.1" 400 46 POST /release/15 127.0.0.1 - - [12/May/2020:09:13:14 +0200] "POST /release/15 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:13:08 +0200] "POST /listen HTTP/1.1" 200 94 POST /post/15 POST /listen 127.0.0.1 - - [12/May/2020:09:13:14 +0200] "POST /post/15 HTTP/1.1" 400 30 127.0.0.1 - - [12/May/2020:09:13:14 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/5/null 127.0.0.1 - - [12/May/2020:09:13:21 +0200] "POST /acquire/5/null HTTP/1.1" 200 17 POST /call/16 127.0.0.1 - - [12/May/2020:09:13:21 +0200] "POST /call/16 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:13:21 +0200] "POST /listen HTTP/1.1" 200 94 POST /post/11 127.0.0.1 - - [12/May/2020:09:13:21 +0200] "POST /post/11 HTTP/1.1" 400 30 POST /listen POST /release/16 127.0.0.1 - - [12/May/2020:09:13:21 +0200] "POST /release/16 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:13:21 +0200] "POST /listen HTTP/1.1" 200 94 POST /listen POST /acquire/5/null 127.0.0.1 - - [12/May/2020:09:13:22 +0200] "POST /acquire/5/null HTTP/1.1" 200 17 POST /call/17 127.0.0.1 - - [12/May/2020:09:13:22 +0200] "POST /call/17 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:13:22 +0200] "POST /listen HTTP/1.1" 200 94 POST /listen POST /call/17 127.0.0.1 - - [12/May/2020:09:13:22 +0200] "POST /call/17 HTTP/1.1" 200 12 POST /call/17 127.0.0.1 - - [12/May/2020:09:13:28 +0200] "POST /call/17 HTTP/1.1" 200 84 POST /call/17 127.0.0.1 - - [12/May/2020:09:13:29 +0200] "POST /call/17 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:13:22 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/6/null 127.0.0.1 - - [12/May/2020:09:13:31 +0200] "POST /acquire/6/null HTTP/1.1" 200 17 POST /call/18 127.0.0.1 - - [12/May/2020:09:13:31 +0200] "POST /call/18 HTTP/1.1" 200 340 127.0.0.1 - - [12/May/2020:09:13:31 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /release/18 127.0.0.1 - - [12/May/2020:09:13:31 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:13:31 +0200] "POST /release/18 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:13:31 +0200] "POST /listen HTTP/1.1" 200 94 POST /post/17 127.0.0.1 - - [12/May/2020:09:13:34 +0200] "POST /post/17 HTTP/1.1" 400 30 POST /listen POST /acquire/6/null 127.0.0.1 - - [12/May/2020:09:13:34 +0200] "POST /acquire/6/null HTTP/1.1" 200 17 POST /call/19 127.0.0.1 - - [12/May/2020:09:13:34 +0200] "POST /listen HTTP/1.1" 200 94 POST /listen 127.0.0.1 - - [12/May/2020:09:13:34 +0200] "POST /call/19 HTTP/1.1" 200 410 POST /call/19 127.0.0.1 - - [12/May/2020:09:13:34 +0200] "POST /call/19 HTTP/1.1" 200 12 POST /call/19 127.0.0.1 - - [12/May/2020:09:13:37 +0200] "POST /call/19 HTTP/1.1" 200 84 POST /call/19 127.0.0.1 - - [12/May/2020:09:13:39 +0200] "POST /call/19 HTTP/1.1" 200 340 127.0.0.1 - - [12/May/2020:09:13:34 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/7/null 127.0.0.1 - - [12/May/2020:09:13:39 +0200] "POST /acquire/7/null HTTP/1.1" 200 17 POST /call/20 127.0.0.1 - - [12/May/2020:09:13:39 +0200] "POST /call/20 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:13:39 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /release/20 127.0.0.1 - - [12/May/2020:09:13:40 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:13:40 +0200] "POST /release/20 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:13:40 +0200] "POST /listen HTTP/1.1" 200 94 POST /post/20 127.0.0.1 - - [12/May/2020:09:13:43 +0200] "POST /post/20 HTTP/1.1" 400 30 POST /listen 127.0.0.1 - - [12/May/2020:09:13:43 +0200] "POST /listen HTTP/1.1" 200 3 POST /post/19 POST /listen 127.0.0.1 - - [12/May/2020:09:13:46 +0200] "POST /post/19 HTTP/1.1" 400 30 127.0.0.1 - - [12/May/2020:09:13:46 +0200] "POST /listen HTTP/1.1" 200 94 POST /listen POST /acquire/8/null 127.0.0.1 - - [12/May/2020:09:13:47 +0200] "POST /acquire/8/null HTTP/1.1" 200 17 POST /call/21 127.0.0.1 - - [12/May/2020:09:13:47 +0200] "POST /call/21 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:13:47 +0200] "POST /listen HTTP/1.1" 200 94 POST /listen POST /release/21 127.0.0.1 - - [12/May/2020:09:13:48 +0200] "POST /listen HTTP/1.1" 200 94 POST /listen 127.0.0.1 - - [12/May/2020:09:13:48 +0200] "POST /release/21 HTTP/1.1" 200 17 POST /acquire/8/null 127.0.0.1 - - [12/May/2020:09:13:48 +0200] "POST /acquire/8/null HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:13:48 +0200] "POST /listen HTTP/1.1" 200 94 POST /call/22 POST /listen 127.0.0.1 - - [12/May/2020:09:13:48 +0200] "POST /call/22 HTTP/1.1" 200 264 POST /call/22 127.0.0.1 - - [12/May/2020:09:13:48 +0200] "POST /call/22 HTTP/1.1" 200 12 POST /call/22 127.0.0.1 - - [12/May/2020:09:13:53 +0200] "POST /call/22 HTTP/1.1" 200 84 POST /call/22 127.0.0.1 - - [12/May/2020:09:13:54 +0200] "POST /call/22 HTTP/1.1" 200 264 127.0.0.1 - - [12/May/2020:09:13:48 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /acquire/9/null 127.0.0.1 - - [12/May/2020:09:13:55 +0200] "POST /acquire/9/null HTTP/1.1" 200 17 POST /call/23 127.0.0.1 - - [12/May/2020:09:13:55 +0200] "POST /call/23 HTTP/1.1" 200 340 127.0.0.1 - - [12/May/2020:09:13:55 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /release/23 127.0.0.1 - - [12/May/2020:09:13:55 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:13:55 +0200] "POST /release/23 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:13:55 +0200] "POST /listen HTTP/1.1" 200 5 POST / 127.0.0.1 - - [12/May/2020:09:14:02 +0200] "POST / HTTP/1.1" 200 21 POST /enumerate 127.0.0.1 - - [12/May/2020:09:14:02 +0200] "POST /enumerate HTTP/1.1" 200 186 POST /listen POST /acquire/9/null 127.0.0.1 - - [12/May/2020:09:14:02 +0200] "POST /acquire/9/null HTTP/1.1" 200 17 POST /call/24 127.0.0.1 - - [12/May/2020:09:14:02 +0200] "POST /call/24 HTTP/1.1" 200 340 127.0.0.1 - - [12/May/2020:09:14:02 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen POST /release/24 127.0.0.1 - - [12/May/2020:09:14:03 +0200] "POST /listen HTTP/1.1" 200 186 POST /listen 127.0.0.1 - - [12/May/2020:09:14:03 +0200] "POST /release/24 HTTP/1.1" 200 17 POST /acquire/8/22 127.0.0.1 - - [12/May/2020:09:14:06 +0200] "POST /acquire/8/22 HTTP/1.1" 200 17 127.0.0.1 - - [12/May/2020:09:14:03 +0200] "POST /listen HTTP/1.1" 200 186 POST /call/25 POST /listen 127.0.0.1 - - [12/May/2020:09:14:06 +0200] "POST /call/25 HTTP/1.1" 200 264 POST /release/25 ================== WARNING: DATA RACE Write at 0x00c000202600 by goroutine 10: runtime.mapdelete_faststr() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/runtime/map_faststr.go:297 +0x0 github.com/trezor/trezord-go/core.(*Core).release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:357 +0x1fc github.com/trezor/trezord-go/core.(*Core).Release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:343 +0x138 github.com/trezor/trezord-go/server/api.(*api).release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/api.go:157 +0xef github.com/trezor/trezord-go/server/api.(*api).Release() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/api.go:144 +0x64 github.com/trezor/trezord-go/server/api.(*api).Release-fm() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/api.go:143 +0x22 net/http.HandlerFunc.ServeHTTP() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2012 +0x51 github.com/trezor/trezord-go/server/api.(*cors).ServeHTTP() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/api/cors.go:69 +0x583 github.com/trezor/trezord-go/vendor/github.com/gorilla/mux.(*Router).ServeHTTP() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/vendor/github.com/gorilla/mux/mux.go:159 +0x193 github.com/trezor/trezord-go/vendor/github.com/gorilla/handlers.loggingHandler.ServeHTTP() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/vendor/github.com/gorilla/handlers/handlers.go:69 +0x309 github.com/trezor/trezord-go/vendor/github.com/gorilla/handlers.(*loggingHandler).ServeHTTP() :1 +0xa6 github.com/trezor/trezord-go/server.(*Server).logRequest.func1() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/http.go:82 +0x277 net/http.HandlerFunc.ServeHTTP() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2012 +0x51 net/http.serverHandler.ServeHTTP() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2807 +0xce net/http.(*conn).serve() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:1895 +0x837 Previous read at 0x00c000202600 by goroutine 9: runtime.mapiterinit() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/runtime/map.go:797 +0x0 github.com/trezor/trezord-go/core.(*Core).releaseDisconnected() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:323 +0xb9 github.com/trezor/trezord-go/core.(*Core).Enumerate() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:266 +0x40f github.com/trezor/trezord-go/core.(*Core).backgroundListen() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:185 +0x106 Goroutine 10 (running) created at: net/http.(*Server).Serve() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2933 +0x5b6 net/http.(*Server).ListenAndServe() /nix/store/gvw1mfpdrk7i82884yhxf9lf5j3c12zm-go-1.14.1/share/go/src/net/http/server.go:2830 +0x102 github.com/trezor/trezord-go/server.(*Server).Run() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/server/http.go:87 +0x1441 main.main() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/trezord.go:178 +0x1424 Goroutine 9 (running) created at: github.com/trezor/trezord-go/core.New() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/core/core.go:160 +0x1e4 main.main() /home/tsusanka/Projects/go/src/github.com/trezor/trezord-go/trezord.go:169 +0x12e7 ================== ```

My early assumption is there is a mutex lock missing in the release function.

tsusanka commented 4 years ago

In particular, I believe this should be wrapped with c.sessionsMutex lock as well. I fail to see any reasons to omit the lock.