"fatal error: concurrent map writes" during restore on Linux with Duplicacy CLI 2.2.3 / Duplicacy Web Edition Beta 1.0.0 (C60C7C)

archon810 · 6 August 2019 05:29

Please describe what you are doing to trigger the bug:

Started Duplicacy for the first time on a Linux (OpenSUSE 15.1) server the other day.
Backed up a test Wordpress install to Google Drive.
Just tried a full restore to a local temp dir. Several percent into it, I clicked on the restore to see progress. When I clicked back, I found the server crashed with “fatal error: concurrent map writes”.

Duplicacy CLI 2.2.3
Duplicacy Web Edition Beta 1.0.0 (C60C7C)

Since this is my first interaction with Duplicacy (I’m also testing Duplicati and rclone for a backup that’ll eventually span 10TB+.

Please describe what you expect to happen (but doesn’t):
No crash, obviously.

Please describe what actually happens (the wrong behaviour):
Here’s the log:

fatal error: concurrent map writes

goroutine 7492 [running]:
runtime.throw(0xcf3a16, 0x15)
        /usr/local/go/src/runtime/panic.go:616 +0x81 fp=0xc423f33a18 sp=0xc423f339f8 pc=0x42a861
runtime.mapassign_faststr(0xbce920, 0xc4201bb110, 0xc420fe5599, 0x40, 0xbf4ab56d1ba1822a)
        /usr/local/go/src/runtime/hashmap_fast.go:703 +0x3e9 fp=0xc423f33a88 sp=0xc423f33a18 pc=0x40b729
main.logHTTPRequest.func1(0xe437c0, 0xc42021fdc0, 0xc4206c7700)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:606 +0x811 fp=0xc423f33d30 sp=0xc423f33a88 pc=0xad4c31
net/http.HandlerFunc.ServeHTTP(0xc420328f80, 0xe437c0, 0xc42021fdc0, 0xc4206c7700)
        /usr/local/go/src/net/http/server.go:1947 +0x44 fp=0xc423f33d58 sp=0xc423f33d30 pc=0x6a9f84
net/http.serverHandler.ServeHTTP(0xc420085380, 0xe437c0, 0xc42021fdc0, 0xc4206c7700)
        /usr/local/go/src/net/http/server.go:2697 +0xbc fp=0xc423f33d88 sp=0xc423f33d58 pc=0x6acecc
net/http.(*conn).serve(0xc4200bd860, 0xe44240, 0xc42072aec0)
        /usr/local/go/src/net/http/server.go:1830 +0x651 fp=0xc423f33fc8 sp=0xc423f33d88 pc=0x6a8fa1
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc423f33fd0 sp=0xc423f33fc8 pc=0x4569c1
created by net/http.(*Server).Serve
        /usr/local/go/src/net/http/server.go:2798 +0x27b

goroutine 1 [IO wait]:
internal/poll.runtime_pollWait(0x7f7e5c44ae30, 0x72, 0x0)
        /usr/local/go/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc4203a6e98, 0x72, 0xc42006c000, 0x0, 0x0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
internal/poll.(*pollDesc).waitRead(0xc4203a6e98, 0xffffffffffffff00, 0x0, 0x0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Accept(0xc4203a6e80, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /usr/local/go/src/internal/poll/fd_unix.go:372 +0x1a8
net.(*netFD).accept(0xc4203a6e80, 0x401127, 0xc4200bd8e0, 0xbb8520)
        /usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc42008c850, 0x4535c0, 0xc4203b9720, 0xc4203b9728)
        /usr/local/go/src/net/tcpsock_posix.go:136 +0x2e
net.(*TCPListener).Accept(0xc42008c850, 0xdb4218, 0xc4200bd860, 0xe44300, 0xc4203ed9b0)
        /usr/local/go/src/net/tcpsock.go:259 +0x49
net/http.(*Server).Serve(0xc420085380, 0xe43500, 0xc42008c850, 0x0, 0x0)
        /usr/local/go/src/net/http/server.go:2773 +0x1a5
net/http.Serve(0xe43500, 0xc42008c850, 0xe3cbe0, 0xc420328f80, 0x1, 0xc4204b6b80)
        /usr/local/go/src/net/http/server.go:2392 +0x73
main.onReady()
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:473 +0x1bcb
main.runSystray(0xdb3f60, 0xdb3f30)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_systray_linux.go:12 +0x41
main.main()  
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:170 +0x53

goroutine 18 [chan receive, 1892 minutes]:
gopkg.in/natefinch/lumberjack%2ev2.(*Logger).millRun(0xc4200b6a20)
        /Users/chgang/zincbox/go/src/gopkg.in/natefinch/lumberjack.v2/lumberjack.go:379 +0x58
created by gopkg.in/natefinch/lumberjack%2ev2.(*Logger).mill.func1
        /Users/chgang/zincbox/go/src/gopkg.in/natefinch/lumberjack.v2/lumberjack.go:390 +0x7e

goroutine 7490 [IO wait]:
internal/poll.runtime_pollWait(0x7f7e5c44aa20, 0x72, 0xc4203f0e58)
        /usr/local/go/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc4203a6018, 0x72, 0xffffffffffffff00, 0xe3d0e0, 0x11d74d0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
internal/poll.(*pollDesc).waitRead(0xc4203a6018, 0xc420377000, 0x1, 0x1)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc4203a6000, 0xc420377001, 0x1, 0x1, 0x0, 0x0, 0x0)
        /usr/local/go/src/internal/poll/fd_unix.go:157 +0x17d
net.(*netFD).Read(0xc4203a6000, 0xc420377001, 0x1, 0x1, 0xc4203a8240, 0x0, 0xc420340118)
        /usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc42008c018, 0xc420377001, 0x1, 0x1, 0x0, 0x0, 0x0)
        /usr/local/go/src/net/net.go:176 +0x6a
net/http.(*connReader).backgroundRead(0xc420376ff0)
        /usr/local/go/src/net/http/server.go:668 +0x5a
created by net/http.(*connReader).startBackgroundRead
        /usr/local/go/src/net/http/server.go:664 +0xce

goroutine 26 [sleep]:
time.Sleep(0x3b9aca00)
        /usr/local/go/src/runtime/time.go:102 +0x166
main.checkSchedules()
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_schedule.go:518 +0xf86
main.onReady.func1()
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:248 +0x3e
created by main.onReady
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:246 +0x6ca

goroutine 37 [select, 1892 minutes]:
main.onReady.func2(0xc42008c838, 0xc4204b0620, 0xc42008c840)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:344 +0xf7
created by main.onReady
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:339 +0x17ba

goroutine 6260 [sleep]:
time.Sleep(0x3b9aca00)
        /usr/local/go/src/runtime/time.go:102 +0x166
main.showLogHandler(0xe437c0, 0xc4204829a0, 0xc420143a00)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_schedule.go:1101 +0x616
net/http.HandlerFunc.ServeHTTP(0xdb3ff8, 0xe437c0, 0xc4204829a0, 0xc420143a00)
        /usr/local/go/src/net/http/server.go:1947 +0x44
net/http.(*ServeMux).ServeHTTP(0x122a680, 0xe437c0, 0xc4204829a0, 0xc420143a00)
        /usr/local/go/src/net/http/server.go:2340 +0x130
main.logHTTPRequest.func1(0xe437c0, 0xc4204829a0, 0xc420143a00)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:632 +0x1f4
net/http.HandlerFunc.ServeHTTP(0xc420328f80, 0xe437c0, 0xc4204829a0, 0xc420143a00)
        /usr/local/go/src/net/http/server.go:1947 +0x44
net/http.serverHandler.ServeHTTP(0xc420085380, 0xe437c0, 0xc4204829a0, 0xc420143a00)
        /usr/local/go/src/net/http/server.go:2697 +0xbc
net/http.(*conn).serve(0xc420380500, 0xe44240, 0xc420340000)
        /usr/local/go/src/net/http/server.go:1830 +0x651
created by net/http.(*Server).Serve
        /usr/local/go/src/net/http/server.go:2798 +0x27b

goroutine 7491 [runnable]:
reflect.flag.mustBeAssignable(0x198)
        /usr/local/go/src/reflect/value.go:225 +0x1fa
reflect.Value.SetString(0xb77060, 0xc420597a90, 0x198, 0xc42039cb50, 0x6)
        /usr/local/go/src/reflect/value.go:1551 +0x2b
encoding/json.(*decodeState).literalStore(0xc4220c94c8, 0xc421c67c0b, 0x8, 0x1f5, 0xb77060, 0xc420597a90, 0x198, 0x0)
        /usr/local/go/src/encoding/json/decode.go:979 +0x1bb6
encoding/json.(*decodeState).literal(0xc4220c94c8, 0xb77060, 0xc420597a90, 0x198)
        /usr/local/go/src/encoding/json/decode.go:842 +0xd5
encoding/json.(*decodeState).value(0xc4220c94c8, 0xb77060, 0xc420597a90, 0x198)
        /usr/local/go/src/encoding/json/decode.go:411 +0x30d
encoding/json.(*decodeState).object(0xc4220c94c8, 0xb5e0e0, 0xc420597a90, 0x16)
        /usr/local/go/src/encoding/json/decode.go:776 +0x132d
encoding/json.(*decodeState).value(0xc4220c94c8, 0xb5e0e0, 0xc420597a90, 0x16)
        /usr/local/go/src/encoding/json/decode.go:408 +0x2d3
encoding/json.(*decodeState).unmarshal(0xc4220c94c8, 0xb5e0e0, 0xc420597a90, 0x0, 0x0)
        /usr/local/go/src/encoding/json/decode.go:189 +0x1e7
encoding/json.(*Decoder).Decode(0xc4220c94a0, 0xb5e0e0, 0xc420597a90, 0x7f7e5c45a8e0, 0xc42072b140)
        /usr/local/go/src/encoding/json/stream.go:73 +0x1a7
main.getRestoreStatusHandler(0xe437c0, 0xc420482fc0, 0xc420143f00)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_restore.go:679 +0xe9
net/http.HandlerFunc.ServeHTTP(0xdb3e60, 0xe437c0, 0xc420482fc0, 0xc420143f00)
        /usr/local/go/src/net/http/server.go:1947 +0x44
net/http.(*ServeMux).ServeHTTP(0x122a680, 0xe437c0, 0xc420482fc0, 0xc420143f00)
        /usr/local/go/src/net/http/server.go:2340 +0x130
main.logHTTPRequest.func1(0xe437c0, 0xc420482fc0, 0xc420143f00)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_main.go:632 +0x1f4
net/http.HandlerFunc.ServeHTTP(0xc420328f80, 0xe437c0, 0xc420482fc0, 0xc420143f00)
        /usr/local/go/src/net/http/server.go:1947 +0x44
net/http.serverHandler.ServeHTTP(0xc420085380, 0xe437c0, 0xc420482fc0, 0xc420143f00)
        /usr/local/go/src/net/http/server.go:2697 +0xbc
net/http.(*conn).serve(0xc4200bd680, 0xe44240, 0xc4215f6980)
        /usr/local/go/src/net/http/server.go:1830 +0x651
created by net/http.(*Server).Serve
        /usr/local/go/src/net/http/server.go:2798 +0x27b

goroutine 7496 [runnable]:
net/http.(*connReader).backgroundRead(0xc420ded3e0)
        /usr/local/go/src/net/http/server.go:667
created by net/http.(*connReader).startBackgroundRead
        /usr/local/go/src/net/http/server.go:664 +0xce

goroutine 6269 [sleep]:
time.Sleep(0x3b9aca00)
        /usr/local/go/src/runtime/time.go:102 +0x166
main.listFilesHandler.func1(0xc420374370, 0xc42021c126, 0x6)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_restore.go:230 +0x5c
created by main.listFilesHandler
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_restore.go:214 +0x638

goroutine 7162 [IO wait]:
internal/poll.runtime_pollWait(0x7f7e5c44ad60, 0x72, 0xc42050f800)
        /usr/local/go/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc420283058, 0x72, 0xffffffffffffff01, 0xe3d0e0, 0x11d74d0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:85 +0x9b
internal/poll.(*pollDesc).waitRead(0xc420283058, 0xc42033d501, 0xab6, 0xab6)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc420283040, 0xc42033d54a, 0xab6, 0xab6, 0x0, 0x0, 0x0)
        /usr/local/go/src/internal/poll/fd_unix.go:157 +0x17d
os.(*File).read(0xc423f36198, 0xc42033d54a, 0xab6, 0xab6, 0x0, 0x0, 0x3)
        /usr/local/go/src/os/file_unix.go:226 +0x4e
os.(*File).Read(0xc423f36198, 0xc42033d54a, 0xab6, 0xab6, 0x440207, 0x50, 0xb77060)
        /usr/local/go/src/os/file.go:107 +0x6a
bufio.(*Scanner).Scan(0xc42050fc88, 0x17)
        /usr/local/go/src/bufio/scan.go:208 +0xbf
main.runDuplicacyExecutable(0xc420228750, 0x2f, 0xc420f1ed00, 0x2, 0x2, 0xc421012900, 0x9, 0x10, 0xc420fe52d0, 0xc42050fec0, ...)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_utils.go:313 +0x5d9
main.startRestoreHandler.func2(0xc4211da4d8, 0xc420261fa0, 0x1b, 0xc42016a2a0, 0xc4204bb250, 0x5, 0xc420f1ed00, 0x2, 0x2, 0xc4207f9080, ...)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_restore.go:579 +0x5fe
created by main.startRestoreHandler
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_restore.go:533 +0x99d

goroutine 7161 [sleep]:
time.Sleep(0x3b9aca00)
        /usr/local/go/src/runtime/time.go:102 +0x166
main.startRestoreHandler.func1(0xc42016a2a0, 0xc4207f9080, 0xc4204bb256, 0x6)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_restore.go:529 +0x6f
created by main.startRestoreHandler
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_restore.go:511 +0x8ef

goroutine 7149 [select, 4 minutes]:
main.runDuplicacyExecutable.func1(0xc420fe52d0, 0xc421300dc0, 0xc42039d538, 0xc420ad0e00)
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_utils.go:293 +0xdd
created by main.runDuplicacyExecutable
        /Users/chgang/zincbox/go/src/github.com/gilbertchen/duplicacy-web/dwe/dwe_utils.go:290 +0xf88

Droolio · 6 August 2019 13:56

This is very likely related to your discovery about leaving the Restore tab:

archon810 · 6 August 2019 15:12

Thing is, I’m pretty sure the 2nd time I didn’t leave the window and it still crashed roughly in the same spot of the restore.

archon810 · 8 August 2019 06:49

I’ve gotten pretty good at the duplicacy cli, but I was wondering if you had any idea what this restore crash was caused by yet and whether it could be fixed, as it makes the web gui quite useless to me otherwise?

Thanks.

TheBestPessimist · 8 August 2019 10:51

also pinging @gchen here