Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Crash during recovery #74

Closed
wtogami opened this issue Jun 3, 2022 · 2 comments
Closed

Crash during recovery #74

wtogami opened this issue Jun 3, 2022 · 2 comments
Labels
bug Something isn't working

Comments

@wtogami
Copy link
Contributor

wtogami commented Jun 3, 2022

After the crash documented in #73 subsequent peerswap startup crashed. It might be difficult to reproduce this state later so documenting it here as peerswap needs to be able to recover from weird states.

2022-06-03T10:56:18.851Z INFO    lightningd: --------------------------------------------------
2022-06-03T10:56:18.851Z INFO    lightningd: Server started with public key REDACTED, alias HONEYPOT (color #01dc50) and lightningd v0.10.2
2022-06-03T10:56:19.024Z INFO    plugin-peerswap-plugin: PeerSwap Initialized, running PeerSwap commit 1f0e91fe95b5e8124d035628cb91623fea462b50
2022-06-03T10:56:19.757Z INFO    plugin-peerswap-plugin: Liquid swaps enabled
2022-06-03T10:56:20.209Z INFO    plugin-peerswap-plugin: Bitcoin swaps enabled
2022-06-03T10:56:20.259Z INFO    plugin-peerswap-plugin: using policy:
2022-06-03T10:56:20.259Z INFO    plugin-peerswap-plugin: reserve_onchain_msat: 0
2022-06-03T10:56:20.259Z INFO    plugin-peerswap-plugin: allowlisted_peers: [REDACTED MANY PUBKEYS]
2022-06-03T10:56:20.260Z INFO    plugin-peerswap-plugin: accept_all_peers: false
2022-06-03T10:56:20.260Z INFO    plugin-peerswap-plugin:
2022-06-03T10:56:20.628Z INFO    plugin-peerswap-plugin: [Swap:6a0fbd775103b48e08ac7bf3e873637cc539442ee1a64d05710fcc62e4a37560]: Recovering from state State_SwapOutReceiver_AwaitClaimInvoicePayment
2022-06-03T10:56:20.640Z INFO    plugin-peerswap-plugin: peerswap initialized
2022-06-03T10:56:23.093Z DEBUG   plugin-peerswap-plugin: [Payment Notifier] Error 903:invoice expired during wait
2022-06-03T10:56:35.585Z DEBUG   plugin-peerswap-plugin: [FSM] event:id: 6a0fbd775103b48e08ac7bf3e873637cc539442ee1a64d05710fcc62e4a37560, Event_OnCsvPassed on State_SwapOutReceiver_AwaitClaimInvoicePayment
2022-06-03T10:56:36.524Z INFO    plugin-peerswap-plugin: Killing plugin: exited during normal operation

fatal: morestack on g0
SIGTRAP: trace trap
PC=0x466a02 m=4 sigcode=128
signal arrived during cgo execution

goroutine 46 [syscall]:
runtime.cgocall(0x7069f0, 0xc0001d1328)
	/usr/local/src/runtime/cgocall.go:157 +0x5c fp=0xc0001d1300 sp=0xc0001d12c8 pc=0x4078bc
github.com/vulpemventures/go-secp256k1-zkp._Cfunc_secp256k1_context_create(0x301)
	_cgo_gotypes.go:298 +0x4d fp=0xc0001d1328 sp=0xc0001d1300 pc=0x6bd0cd
github.com/vulpemventures/go-secp256k1-zkp.ContextCreate(0x301)
	/root/go/pkg/mod/github.com/vulpemventures/[email protected]/secp256k1.go:74 +0x37 fp=0xc0001d1350 sp=0xc0001d1328 pc=0x6c1817
github.com/vulpemventures/go-elements/confidential.nonceHash({0xc0005ac900, 0x21, 0x30}, {0xc000490f20, 0x20, 0x20})
	/root/go/pkg/mod/github.com/vulpemventures/[email protected]/confidential/confidential.go:175 +0x7b fp=0xc0001d13d0 sp=0xc0001d1350 pc=0x6c2bdb
github.com/vulpemventures/go-elements/confidential.NonceHash(...)
	/root/go/pkg/mod/github.com/vulpemventures/[email protected]/confidential/confidential.go:16
github.com/vulpemventures/go-elements/confidential.UnblindOutputWithKey(0xc0002283f0, {0xc000490f20?, 0x3?, 0x90?})
	/root/go/pkg/mod/github.com/vulpemventures/[email protected]/confidential/confidential.go:39 +0x6a fp=0xc0001d1470 sp=0xc0001d13d0 pc=0x6c2a8a
github.com/elementsproject/peerswap/onchain.(*LiquidOnChain).createSpendingTransaction(0xc0004b2540, {0xc0005c1000, 0x45f4}, 0x186a0, 0x3c, {0xc0004f01b0, 0x21, 0x30}, {0xc0005d5a00, 0x98, ...}, ...)
	/opt/plugins/ps/onchain/liquid.go:273 +0x230 fp=0xc0001d19d0 sp=0xc0001d1470 pc=0x6cd610
github.com/elementsproject/peerswap/onchain.(*LiquidOnChain).prepareSpendingTransaction(0xc0004b2540, 0xc00049d4f0, 0xc0001aa380, {0xc0000c4540, 0x65}, 0x68?, 0x7f0bc17d85b8?)
	/opt/plugins/ps/onchain/liquid.go:246 +0x1b0 fp=0xc0001d1b20 sp=0xc0001d19d0 pc=0x6cd250
github.com/elementsproject/peerswap/onchain.(*LiquidOnChain).CreateCsvSpendingTransaction(0xc0004b2540, 0x7a6583?, 0x40?)
	/opt/plugins/ps/onchain/liquid.go:164 +0xad fp=0xc0001d1bf8 sp=0xc0001d1b20 pc=0x6cc2ad
github.com/elementsproject/peerswap/swap.(*ClaimSwapTransactionWithCsv).Execute(0xc000211200?, 0xc00057a1c0?, 0xc0005b2480)
	/opt/plugins/ps/swap/actions.go:410 +0x94 fp=0xc0001d1c40 sp=0xc0001d1bf8 pc=0x6a02d4
github.com/elementsproject/peerswap/swap.StopSendMessageWithRetryWrapperAction.Execute({{0x95c8a0?, 0xb872e0?}}, 0xc0000bc2a0, 0xc0005b2480)
	/opt/plugins/ps/swap/actions.go:260 +0xd0 fp=0xc0001d1c80 sp=0xc0001d1c40 pc=0x69eeb0
github.com/elementsproject/peerswap/swap.(*StopSendMessageWithRetryWrapperAction).Execute(0xc0005b0150?, 0xc0004f7fb0?, 0x7b493b?)
	<autogenerated>:1 +0x3d fp=0xc0001d1cb0 sp=0xc0001d1c80 pc=0x6b567d
github.com/elementsproject/peerswap/swap.(*SwapStateMachine).SendEvent(0xc0005b0150, {0x7ab008, 0x11}, {0x0?, 0x0})
	/opt/plugins/ps/swap/fsm.go:187 +0x6f4 fp=0xc0001d1da0 sp=0xc0001d1cb0 pc=0x6a2a34
github.com/elementsproject/peerswap/swap.(*SwapService).OnCsvPassed(0x40?, {0xc0005d04c0?, 0xc000660840?})
	/opt/plugins/ps/swap/service.go:297 +0x4d fp=0xc0001d1e28 sp=0xc0001d1da0 pc=0x6a734d
github.com/elementsproject/peerswap/swap.(*SwapService).OnCsvPassed-fm({0xc0005d04c0?, 0xc00057b040?})
	<autogenerated>:1 +0x34 fp=0xc0001d1e50 sp=0xc0001d1e28 pc=0x6b4fd4
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).HandleCsvTx(0xc0004a4c60, 0xc00003df80?)
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:195 +0x194 fp=0xc0001d1f48 sp=0xc0001d1e50 pc=0x6e8ab4
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs.func1()
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:102 +0xf4 fp=0xc0001d1fd0 sp=0xc0001d1f48 pc=0x6e8094
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs.func3()
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:110 +0x24 fp=0xc0001d1fe0 sp=0xc0001d1fd0 pc=0x6e7f64
runtime.goexit()
	/usr/local/src/runtime/asm_amd64.s:1571 +0x1 fp=0xc0001d1fe8 sp=0xc0001d1fe0 pc=0x466ba1
created by github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:86 +0x15b

goroutine 1 [chan receive]:
main.run()
	/opt/plugins/ps/cmd/peerswap-plugin/main.go:259 +0x10e5
main.main()
	/opt/plugins/ps/cmd/peerswap-plugin/main.go:55 +0xe5

goroutine 8 [syscall]:
syscall.Syscall(0x0, 0x0, 0xc0000da400, 0x400)
	/usr/local/src/syscall/asm_linux_amd64.s:20 +0x5
syscall.read(0xc00006c060?, {0xc0000da400?, 0x41b54b?, 0x7f0b9acb6f00?})
	/usr/local/src/syscall/zsyscall_linux_amd64.go:696 +0x4d
syscall.Read(...)
	/usr/local/src/syscall/syscall_unix.go:188
internal/poll.ignoringEINTRIO(...)
	/usr/local/src/internal/poll/fd_unix.go:794
internal/poll.(*FD).Read(0xc00006c060?, {0xc0000da400?, 0x400?, 0x400?})
	/usr/local/src/internal/poll/fd_unix.go:163 +0x285
os.(*File).read(...)
	/usr/local/src/os/file_posix.go:31
os.(*File).Read(0xc000010010, {0xc0000da400?, 0xc00003d588?, 0x46fa46?})
	/usr/local/src/os/file.go:119 +0x5e
bufio.(*Scanner).Scan(0xc00003d688)
	/usr/local/src/bufio/scan.go:215 +0x865
github.com/elementsproject/glightning/jrpc2.(*Server).listen(0xc00006a280, {0x95cf60?, 0xc000010010?})
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/server.go:108 +0xef
github.com/elementsproject/glightning/jrpc2.(*Server).StartUp(0xc00006a280, 0xc0004b2040?, 0xc000010018)
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/server.go:69 +0xa7
github.com/elementsproject/glightning/glightning.(*Plugin).Start(0xc000090000, 0x0?, 0x0?)
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/glightning/plugin.go:1294 +0x149
github.com/elementsproject/peerswap/clightning.(*ClightningClient).Start(...)
	/opt/plugins/ps/clightning/clightning.go:200
main.run.func1()
	/opt/plugins/ps/cmd/peerswap-plugin/main.go:83 +0x3d
created by main.run
	/opt/plugins/ps/cmd/peerswap-plugin/main.go:82 +0x13f

goroutine 18 [select]:
io.(*pipe).read(0xc0004a4000, {0xc0000ba000, 0x1000, 0x1?})
	/usr/local/src/io/pipe.go:57 +0xb1
io.(*PipeReader).Read(0x0?, {0xc0000ba000?, 0x0?, 0x0?})
	/usr/local/src/io/pipe.go:136 +0x25
bufio.(*Scanner).Scan(0xc000051f28)
	/usr/local/src/bufio/scan.go:215 +0x865
github.com/elementsproject/glightning/glightning.(*Plugin).checkForMonkeyPatch.func1({0x95cc40?, 0xc0004a6000?}, 0xc000090000)
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/glightning/plugin.go:1327 +0xaf
created by github.com/elementsproject/glightning/glightning.(*Plugin).checkForMonkeyPatch
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/glightning/plugin.go:1324 +0x27b

goroutine 19 [chan receive]:
github.com/elementsproject/glightning/jrpc2.(*Server).setupWriteQueue(0xc00006a280, {0x95cf80?, 0xc000010018?})
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/server.go:132 +0x125
created by github.com/elementsproject/glightning/jrpc2.(*Server).StartUp
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/server.go:68 +0x91

goroutine 9 [chan receive]:
github.com/elementsproject/glightning/jrpc2.(*Client).setupWriteQueue(0xc0000760a0, {0x7f0b9aa3d198?, 0xc000010360?})
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/client.go:91 +0x165
github.com/elementsproject/glightning/jrpc2.(*Client).SocketStart(0xc0000760a0, {0xc0000266f0, 0x26}, 0xc0000802a0)
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/client.go:64 +0x1c5
github.com/elementsproject/glightning/glightning.(*Lightning).StartUp.func1(0xc000021150, {0xc00002cee0?, 0x665192?}, {0xc000028288?, 0xc0000da800?}, 0x3ac?, 0x3ac?)
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/glightning/lightning.go:34 +0x85
created by github.com/elementsproject/glightning/glightning.(*Lightning).StartUp
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/glightning/lightning.go:33 +0x165

goroutine 10 [IO wait]:
internal/poll.runtime_pollWait(0x7f0b9aa3b758, 0x72)
	/usr/local/src/runtime/netpoll.go:302 +0x89
internal/poll.(*pollDesc).wait(0xc000022480?, 0xc0003b8002?, 0x0)
	/usr/local/src/internal/poll/fd_poll_runtime.go:83 +0x32
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/src/internal/poll/fd_poll_runtime.go:88
internal/poll.(*FD).Read(0xc000022480, {0xc0003b8002, 0x7fdfe, 0x7fdfe})
	/usr/local/src/internal/poll/fd_unix.go:167 +0x25a
net.(*netFD).Read(0xc000022480, {0xc0003b8002?, 0xc000629950?, 0x203000?})
	/usr/local/src/net/fd_posix.go:55 +0x29
net.(*conn).Read(0xc000010360, {0xc0003b8002?, 0xc0003b8000?, 0xc000239ee0?})
	/usr/local/src/net/net.go:183 +0x45
encoding/json.(*Decoder).refill(0xc0000e0280)
	/usr/local/src/encoding/json/stream.go:165 +0x17f
encoding/json.(*Decoder).readValue(0xc0000e0280)
	/usr/local/src/encoding/json/stream.go:140 +0xbb
encoding/json.(*Decoder).Decode(0xc0000e0280, {0x74d8c0, 0xc000204d20})
	/usr/local/src/encoding/json/stream.go:63 +0x78
github.com/elementsproject/glightning/jrpc2.(*Client).readQueue(0xc0000760a0, {0x95cd80?, 0xc000010360})
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/client.go:113 +0xab
github.com/elementsproject/glightning/jrpc2.(*Client).SocketStart.func1({0x9604d8?, 0xc000010360}, 0x3ac?)
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/client.go:62 +0x6b
created by github.com/elementsproject/glightning/jrpc2.(*Client).SocketStart
	/root/go/pkg/mod/github.com/elementsproject/[email protected]/jrpc2/client.go:58 +0x19e

goroutine 45 [select]:
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartBlockWatcher(0xc0004a4c60, 0x1c675c)
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:120 +0xf6
created by github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:85 +0xc9

goroutine 47 [select]:
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartBlockWatcher(0xc00006cb40, 0xb472a)
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:120 +0xf6
created by github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:85 +0xc9

goroutine 48 [sleep]:
time.Sleep(0x5f5e100)
	/usr/local/src/runtime/time.go:194 +0x12e
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs.func1()
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:107 +0x135
created by github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:86 +0x15b

goroutine 448 [sleep]:
time.Sleep(0x2540be400)
	/usr/local/src/runtime/time.go:194 +0x12e
github.com/elementsproject/peerswap/clightning.(*ClightningClient).OnConnect.func1()
	/opt/plugins/ps/clightning/clightning.go:417 +0x35
created by github.com/elementsproject/peerswap/clightning.(*ClightningClient).OnConnect
	/opt/plugins/ps/clightning/clightning.go:415 +0x72

goroutine 416 [sleep]:
time.Sleep(0x2540be400)
	/usr/local/src/runtime/time.go:194 +0x12e
github.com/elementsproject/peerswap/clightning.(*ClightningClient).OnConnect.func1()
	/opt/plugins/ps/clightning/clightning.go:417 +0x35
created by github.com/elementsproject/peerswap/clightning.(*ClightningClient).OnConnect
	/opt/plugins/ps/clightning/clightning.go:415 +0x72

goroutine 468 [semacquire]:
sync.runtime_SemacquireMutex(0x655880?, 0x20?, 0xc00062fec0?)
	/usr/local/src/runtime/sema.go:71 +0x25
sync.(*Mutex).lockSlow(0xc0004a4cb0)
	/usr/local/src/sync/mutex.go:162 +0x165
sync.(*Mutex).Lock(...)
	/usr/local/src/sync/mutex.go:81
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).HandleConfirmedTx(0xc0004a4c60, 0xc00063fc20?)
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:141 +0x52
github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs.func1.1()
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:96 +0x25
created by github.com/elementsproject/peerswap/txwatcher.(*BlockchainRpcTxWatcher).StartWatchingTxs.func1
	/opt/plugins/ps/txwatcher/rpctxwatcher.go:95 +0xe5

goroutine 220 [select]:
github.com/elementsproject/peerswap/poll.(*Service).Start.func1()
	/opt/plugins/ps/poll/service.go:89 +0xa5
created by github.com/elementsproject/peerswap/poll.(*Service).Start
	/opt/plugins/ps/poll/service.go:87 +0x5b

rax    0x17
rbx    0x7ae43c
rcx    0x4683d5
rdx    0x17
rdi    0x2
rsi    0x7ae43c
rbp    0x5de5
rsp    0x7f0b9ab0c2e8
r8     0x625295ed0
r9     0x54b451c2dd668
r10    0x38b0684
r11    0x246
r12    0x1311edb5f1895b
r13    0xdd84880
r14    0xc000003520
r15    0xcfdfcc60
rip    0x466a02
rflags 0x206
cs     0x33
fs     0x0
gs     0x0
@wtogami wtogami assigned wtogami and unassigned wtogami Jun 3, 2022
@wtogami wtogami added this to the v0.3.0 milestone Jun 3, 2022
@wtogami wtogami added the bug Something isn't working label Jun 3, 2022
@nepet
Copy link
Contributor

nepet commented Jul 1, 2022

Just for reference: The logs of #73 and #74 are mixed up. The panic log in #73 is the recovery crash.

@nepet
Copy link
Contributor

nepet commented Jul 8, 2022

I asked vulpem ventures for help on this crash as it seems that the cgo call for secp256k1 crashed and I dont know why vulpemventures/go-elements#203

@nepet nepet mentioned this issue Jul 11, 2022
Merged
nepet added a commit to nepet/peerswap that referenced this issue Jul 11, 2022
@nepet
txwatcher: Add nil check before calling the blockchain rpc
58a34c6 
We encountered an error with a missing blockchain client in ElementsProject#74. This
was not reproducible by now so we hope this log will help solving
this issue in the future.
nepet added a commit to nepet/peerswap that referenced this issue Jul 13, 2022
@nepet
txwatcher: Add nil check before calling the blockchain rpc
427fd4a 
We encountered an error with a missing blockchain client in ElementsProject#74. This
was not reproducible by now so we hope this log will help solving
this issue in the future.
nepet added a commit to nepet/peerswap that referenced this issue Jul 17, 2022
@nepet
txwatcher: Add nil check before calling the blockchain rpc
6135d8d 
We encountered an error with a missing blockchain client in ElementsProject#74. This
was not reproducible by now so we hope this log will help solving
this issue in the future.
@nepet nepet removed this from the v0.3.0 milestone Sep 29, 2022
@wtogami wtogami closed this as completed Jul 18, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@wtogami @nepet