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

Investigate crash during libusb_get_active_config_descriptor #221

Closed prusnak closed 3 years ago

prusnak commented 3 years ago 
2020/12/09 14:15:24 trezord v2.0.30 is starting.
POST /
127.0.0.1 - - [09/Dec/2020:14:15:29 +0100] "POST / HTTP/1.1" 200 21
POST /enumerate
127.0.0.1 - - [09/Dec/2020:14:15:29 +0100] "POST /enumerate HTTP/1.1" 200 94
POST /acquire/1/null
POST /listen
127.0.0.1 - - [09/Dec/2020:14:15:30 +0100] "POST /acquire/1/null HTTP/1.1" 200 16
POST /call/1
127.0.0.1 - - [09/Dec/2020:14:15:30 +0100] "POST /listen HTTP/1.1" 200 93
POST /listen
127.0.0.1 - - [09/Dec/2020:14:15:32 +0100] "POST /call/1 HTTP/1.1" 200 408
POST /release/1
127.0.0.1 - - [09/Dec/2020:14:15:34 +0100] "POST /release/1 HTTP/1.1" 200 16
POST /acquire/1/null
fatal error: unexpected signal during runtime execution
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x43ddfa9]

runtime stack:
runtime.throw(0x44f3760, 0x2a)
/usr/local/go/src/runtime/panic.go:774 +0x72
runtime.sigpanic()
/usr/local/go/src/runtime/signal_unix.go:378 +0x47c

goroutine 21 [syscall]:
runtime.cgocall(0x43ea9c0, 0xc0000f5a98, 0xc000112180)
/usr/local/go/src/runtime/cgocall.go:128 +0x5b fp=0xc0000f5a68 sp=0xc0000f5a30 pc=0x40051db
github.com/trezor/trezord-go/usb/lowlevel/libusb._Cfunc_libusb_get_active_config_descriptor(0x4d009e0, 0xc000112180, 0xc000000000)
_cgo_gotypes.go:849 +0x4d fp=0xc0000f5a98 sp=0xc0000f5a68 pc=0x43c730d
github.com/trezor/trezord-go/usb/lowlevel/libusb.Get_Active_Config_Descriptor.func1(0x4d009e0, 0xc000112180, 0x43d1c00)
/ext-go/1/src/github.com/trezor/trezord-go/usb/lowlevel/libusb/libusb.go:1189 +0xd2 fp=0xc0000f5ad0 sp=0xc0000f5a98 pc=0x43cdbd2
github.com/trezor/trezord-go/usb/lowlevel/libusb.Get_Active_Config_Descriptor(0x4d009e0, 0x44eb63f, 0x1a, 0x0)
/ext-go/1/src/github.com/trezor/trezord-go/usb/lowlevel/libusb/libusb.go:1189 +0x49 fp=0xc0000f5b08 sp=0xc0000f5ad0 pc=0x43ccbd9
github.com/trezor/trezord-go/usb.(*LibUSB).match(0xc00009ccc0, 0x4d009e0, 0x1a, 0x6)
/ext-go/1/src/github.com/trezor/trezord-go/usb/libusb.go:361 +0x103 fp=0xc0000f5b88 sp=0xc0000f5b08 pc=0x43d1d03
github.com/trezor/trezord-go/usb.(*LibUSB).Enumerate(0xc00009ccc0, 0x0, 0x0, 0x0, 0x0, 0x0)
/ext-go/1/src/github.com/trezor/trezord-go/usb/libusb.go:145 +0x229 fp=0xc0000f5db0 sp=0xc0000f5b88 pc=0x43d08b9
github.com/trezor/trezord-go/usb.(*USB).Enumerate(0xc00009cd40, 0x44de7ed, 0x3, 0x1, 0x1, 0xc000439320)
/ext-go/1/src/github.com/trezor/trezord-go/usb/bus.go:32 +0xdc fp=0xc0000f5e50 sp=0xc0000f5db0 pc=0x43cea3c
github.com/trezor/trezord-go/core.(*Core).Enumerate(0xc0000fd380, 0x0, 0x0, 0x0, 0x0, 0x0)
/ext-go/1/src/github.com/trezor/trezord-go/core/core.go:250 +0x361 fp=0xc0000f5f60 sp=0xc0000f5e50 pc=0x4106d21
github.com/trezor/trezord-go/core.(*Core).backgroundListen(0xc0000fd380)
/ext-go/1/src/github.com/trezor/trezord-go/core/core.go:184 +0xa6 fp=0xc0000f5fd8 sp=0xc0000f5f60 pc=0x4106076
runtime.goexit()
/usr/local/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0000f5fe0 sp=0xc0000f5fd8 pc=0x405c271
created by github.com/trezor/trezord-go/core.New
/ext-go/1/src/github.com/trezor/trezord-go/core/core.go:159 +0xb5

goroutine 1 [IO wait]:
internal/poll.runtime_pollWait(0x4f18f38, 0x72, 0x0)
/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc000118518, 0x72, 0x0, 0x0, 0x44dfe99)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc000118500, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
/usr/local/go/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc000118500, 0xc04fe2e08a, 0x2cc734fe2e08a, 0x100000001)
/usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc00009df60, 0x5fd0cdf2, 0xc0000f7ba8, 0x40b52a6)
/usr/local/go/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc00009df60, 0xc0000f7bf8, 0x18, 0xc000000180, 0x42cfece)
/usr/local/go/src/net/tcpsock.go:261 +0x47
net/http.(*Server).Serve(0xc0001001c0, 0x4583800, 0xc00009df60, 0x0, 0x0)
/usr/local/go/src/net/http/server.go:2896 +0x286
net/http.(*Server).ListenAndServe(0xc0001001c0, 0x44e7968, 0x13)
/usr/local/go/src/net/http/server.go:2825 +0xb7
github.com/trezor/trezord-go/server.(*Server).Run(...)
/ext-go/1/src/github.com/trezor/trezord-go/server/http.go:87
main.main()
/ext-go/1/src/github.com/trezor/trezord-go/trezord.go:210 +0xc20

goroutine 20 [IO wait]:
internal/poll.runtime_pollWait(0x4f19008, 0x72, 0xffffffffffffffff)
/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc000118218, 0x72, 0x0, 0x40, 0xffffffffffffffff)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000118200, 0xc000430080, 0x40, 0x40, 0x0, 0x0, 0x0)
/usr/local/go/src/internal/poll/fd_unix.go:169 +0x22b
net.(*netFD).Read(0xc000118200, 0xc000430080, 0x40, 0x40, 0xc00003af40, 0x4044e0c, 0x40)
/usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0000a4548, 0xc000430080, 0x40, 0x40, 0x0, 0x0, 0x0)
/usr/local/go/src/net/net.go:184 +0x68
github.com/trezor/trezord-go/usb.listen.func1(0x4f190d8, 0xc0000a4548, 0xc0000a6660, 0xc0000a6600)
/ext-go/1/src/github.com/trezor/trezord-go/usb/udp.go:45 +0x78
created by github.com/trezor/trezord-go/usb.listen
/ext-go/1/src/github.com/trezor/trezord-go/usb/udp.go:42 +0xa2

goroutine 35 [semacquire]:
sync.runtime_SemacquireMutex(0xc0000fd3f4, 0x0, 0x1)
/usr/local/go/src/runtime/sema.go:71 +0x47
sync.(*Mutex).lockSlow(0xc0000fd3f0)
/usr/local/go/src/sync/mutex.go:138 +0xfc
sync.(*Mutex).Lock(...)
/usr/local/go/src/sync/mutex.go:81
github.com/trezor/trezord-go/core.(*Core).Enumerate(0xc0000fd380, 0x0, 0x0, 0x0, 0x0, 0x0)
/ext-go/1/src/github.com/trezor/trezord-go/core/core.go:238 +0x451
github.com/trezor/trezord-go/core.(*Core).Listen(0xc0000fd380, 0xc000108c00, 0x1, 0x4, 0x4585080, 0xc000394930, 0x0, 0x203000, 0x203000, 0x203000, ...)
/ext-go/1/src/github.com/trezor/trezord-go/core/core.go:373 +0x207
github.com/trezor/trezord-go/server/api.(*api).Listen(0xc00009d040, 0x4584500, 0xc0000af3b0, 0xc000108b00)
/ext-go/1/src/github.com/trezor/trezord-go/server/api/api.go:88 +0x20d
net/http.HandlerFunc.ServeHTTP(0xc000364350, 0x4584500, 0xc0000af3b0, 0xc000108b00)
/usr/local/go/src/net/http/server.go:2007 +0x44
github.com/trezor/trezord-go/server/api.(*cors).ServeHTTP(0xc0004161e0, 0x4584500, 0xc0000af3b0, 0xc000108b00)
/ext-go/1/src/github.com/trezor/trezord-go/server/api/cors.go:69 +0x3fe
github.com/gorilla/mux.(*Router).ServeHTTP(0xc000366000, 0x4584500, 0xc0000af3b0, 0xc000108900)
/go/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0xe2
github.com/gorilla/handlers.loggingHandler.ServeHTTP(0x457b9c0, 0xc00009cd60, 0x457b840, 0xc000366000, 0x4502958, 0x4583ac0, 0xc000100460, 0xc000108900)
/go/pkg/mod/github.com/gorilla/handlers@v1.5.1/logging.go:47 +0xe6
github.com/trezor/trezord-go/server.(*Server).logRequest.func1(0x4583ac0, 0xc000100460, 0xc000108900)
/ext-go/1/src/github.com/trezor/trezord-go/server/http.go:82 +0x1cf
net/http.HandlerFunc.ServeHTTP(0xc00009df40, 0x4583ac0, 0xc000100460, 0xc000108900)
/usr/local/go/src/net/http/server.go:2007 +0x44
net/http.serverHandler.ServeHTTP(0xc0001001c0, 0x4583ac0, 0xc000100460, 0xc000108900)
/usr/local/go/src/net/http/server.go:2802 +0xa4
net/http.(*conn).serve(0xc0003a4000, 0x4584fc0, 0xc00011e1c0)
/usr/local/go/src/net/http/server.go:1890 +0x875
created by net/http.(*Server).Serve
/usr/local/go/src/net/http/server.go:2927 +0x38e

goroutine 23 [syscall]:
github.com/trezor/trezord-go/usb/lowlevel/libusb._Cfunc_libusb_reset_device(0x4fcd000, 0x0)
_cgo_gotypes.go:1280 +0x49
github.com/trezor/trezord-go/usb/lowlevel/libusb.Reset_Device.func1(0x4fcd000, 0x481e1c8)
/ext-go/1/src/github.com/trezor/trezord-go/usb/lowlevel/libusb/libusb.go:1094 +0x56
github.com/trezor/trezord-go/usb/lowlevel/libusb.Reset_Device(0x4fcd000, 0x44df8a0, 0x5)
/ext-go/1/src/github.com/trezor/trezord-go/usb/lowlevel/libusb/libusb.go:1094 +0x2b
github.com/trezor/trezord-go/usb.(*LibUSB).connect(0xc00009ccc0, 0x4d009e0, 0x100, 0x0, 0x1, 0xc000112150)
/ext-go/1/src/github.com/trezor/trezord-go/usb/libusb.go:299 +0x248
github.com/trezor/trezord-go/usb.(*LibUSB).Connect(0xc00009ccc0, 0xc000122426, 0x9, 0x4100100, 0x0, 0x0, 0x0, 0x0)
/ext-go/1/src/github.com/trezor/trezord-go/usb/libusb.go:209 +0x34c
github.com/trezor/trezord-go/usb.(*USB).Connect(0xc00009cd40, 0xc000122426, 0x9, 0x100, 0x1, 0xc0004036b0, 0xc, 0x482840a)
/ext-go/1/src/github.com/trezor/trezord-go/usb/bus.go:44 +0x11b
github.com/trezor/trezord-go/core.(*Core).tryConnect(0xc0000fd380, 0xc000122426, 0x9, 0xc0003e0100, 0x1, 0x0, 0x12, 0x4435a60)
/ext-go/1/src/github.com/trezor/trezord-go/core/core.go:488 +0x138
github.com/trezor/trezord-go/core.(*Core).Acquire(0xc0000fd380, 0xc00043914e, 0x1, 0x0, 0x0, 0x400e100, 0xc0003d6f20, 0x160, 0x150, 0x44967c0)
/ext-go/1/src/github.com/trezor/trezord-go/core/core.go:459 +0x3cd
github.com/trezor/trezord-go/server/api.(*api).acquire(0xc00009d040, 0x4584500, 0xc0003a6a50, 0xc00012d000, 0xc0000f9600)
/ext-go/1/src/github.com/trezor/trezord-go/server/api/api.go:125 +0x110
github.com/trezor/trezord-go/server/api.(*api).Acquire(...)
/ext-go/1/src/github.com/trezor/trezord-go/server/api/api.go:111
net/http.HandlerFunc.ServeHTTP(0xc0003644c0, 0x4584500, 0xc0003a6a50, 0xc00012d000)
/usr/local/go/src/net/http/server.go:2007 +0x44
github.com/trezor/trezord-go/server/api.(*cors).ServeHTTP(0xc000114880, 0x4584500, 0xc0003a6a50, 0xc00012d000)
/ext-go/1/src/github.com/trezor/trezord-go/server/api/cors.go:69 +0x3fe
github.com/gorilla/mux.(*Router).ServeHTTP(0xc000366000, 0x4584500, 0xc0003a6a50, 0xc00012ce00)
/go/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0xe2
github.com/gorilla/handlers.loggingHandler.ServeHTTP(0x457b9c0, 0xc00009cd60, 0x457b840, 0xc000366000, 0x4502958, 0x4583ac0, 0xc0003c6380, 0xc00012ce00)
/go/pkg/mod/github.com/gorilla/handlers@v1.5.1/logging.go:47 +0xe6
github.com/trezor/trezord-go/server.(*Server).logRequest.func1(0x4583ac0, 0xc0003c6380, 0xc00012ce00)
/ext-go/1/src/github.com/trezor/trezord-go/server/http.go:82 +0x1cf
net/http.HandlerFunc.ServeHTTP(0xc00009df40, 0x4583ac0, 0xc0003c6380, 0xc00012ce00)
/usr/local/go/src/net/http/server.go:2007 +0x44
net/http.serverHandler.ServeHTTP(0xc0001001c0, 0x4583ac0, 0xc0003c6380, 0xc00012ce00)
/usr/local/go/src/net/http/server.go:2802 +0xa4
net/http.(*conn).serve(0xc00037f220, 0x4584fc0, 0xc0000d3f80)
/usr/local/go/src/net/http/server.go:1890 +0x875
created by net/http.(*Server).Serve
/usr/local/go/src/net/http/server.go:2927 +0x38e

goroutine 26 [IO wait]:
internal/poll.runtime_pollWait(0x4f18e68, 0x72, 0xffffffffffffffff)
/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0003a2018, 0x72, 0x0, 0x1, 0xffffffffffffffff)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc0003a2000, 0xc00010e7f1, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/go/src/internal/poll/fd_unix.go:169 +0x22b
net.(*netFD).Read(0xc0003a2000, 0xc00010e7f1, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc000112048, 0xc00010e7f1, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/go/src/net/net.go:184 +0x68
net/http.(*connReader).backgroundRead(0xc00010e7e0)
/usr/local/go/src/net/http/server.go:677 +0x58
created by net/http.(*connReader).startBackgroundRead
/usr/local/go/src/net/http/server.go:673 +0xd4

goroutine 40 [IO wait]:
internal/poll.runtime_pollWait(0x4f18d98, 0x72, 0xffffffffffffffff)
/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc000118598, 0x72, 0x0, 0x1, 0xffffffffffffffff)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000118580, 0xc000394311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/go/src/internal/poll/fd_unix.go:169 +0x22b
net.(*netFD).Read(0xc000118580, 0xc000394311, 0x1, 0x1, 0xc000406018, 0xc0003acf68, 0x407592c)
/usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0000a4710, 0xc000394311, 0x1, 0x1, 0x0, 0x0, 0x0)
/usr/local/go/src/net/net.go:184 +0x68
net/http.(*connReader).backgroundRead(0xc000394300)
/usr/local/go/src/net/http/server.go:677 +0x58
created by net/http.(*connReader).startBackgroundRead
/usr/local/go/src/net/http/server.go:673 +0xd4
prusnak commented 3 years ago

Can be reproduced on macOS by running test.py

Linux and Windows seem to work just fine.

prusnak commented 3 years ago

It seems the first bad commit is this one: 6043124d851c0c03c1f973fdcda5c8b9b7a6a79a

prusnak commented 3 years ago

It seems that the collision happens between

github.com/trezor/trezord-go/usb/lowlevel/libusb.Get_Active_Config_Descriptor

and

github.com/trezor/trezord-go/usb/lowlevel/libusb.Reset_Device

When one thread tries to enumerate the device, while other calls device reset, this will cause segfault on macOS.

Easy fix seems to be add mutex for Enumerate / Acquire - added in a6c27d7