bitcoin: RPC stuck on walletpassphrase call

Sometimes RPC API stops responding after calling walletpassphrase Unfortunately I can not exactly reproduce this bug. I have tried 20 threads with about 100 requests on each with sequential calling walletpassphrase -> listtransactions -> walletpassphrase -> getransactions, but with no luck.

Observe it four-five times a day and only restart of node could help.

It happens not only for bitcoin wallet on mainnet and testnet, but also for litecoin and bitcoin abc wallets, also for mainnet and testnet

I could provide additional data such as logs, etc.

System information

Bitcoin Core version v0.19.1 Litecoin Core Daemon version v0.17.1 Bitcoin ABC Daemon version v0.19.9.0-2f1adeefb

OS: Debian 10, Xen guest, SSD

debug.log with last call. after that RPC won’t response anymore.

2020-03-31T10:17:47Z received: inv (37 bytes) peer=11
2020-03-31T10:17:47Z got inv: tx bc6099be609e8a81e11b1ba53badd401a3361fe70c8a90dd92cc743ab972b32c  new peer=11
2020-03-31T10:17:47Z Requesting witness-tx bc6099be609e8a81e11b1ba53badd401a3361fe70c8a90dd92cc743ab972b32c peer=11
2020-03-31T10:17:47Z sending getdata (37 bytes) peer=11
2020-03-31T10:17:48Z received: tx (247 bytes) peer=11
2020-03-31T10:17:48Z AcceptToMemoryPool: peer=11: accepted bc6099be609e8a81e11b1ba53badd401a3361fe70c8a90dd92cc743ab972b32c (poolsz 10 txn, 13 kB)
2020-03-31T10:17:48Z sending inv (37 bytes) peer=5
2020-03-31T10:17:48Z received: inv (37 bytes) peer=6
2020-03-31T10:17:48Z got inv: tx bc6099be609e8a81e11b1ba53badd401a3361fe70c8a90dd92cc743ab972b32c  have peer=6
2020-03-31T10:17:48Z sending inv (37 bytes) peer=14
2020-03-31T10:17:48Z sending inv (37 bytes) peer=13
2020-03-31T10:17:49Z received: inv (37 bytes) peer=15
2020-03-31T10:17:49Z got inv: tx bc6099be609e8a81e11b1ba53badd401a3361fe70c8a90dd92cc743ab972b32c  have peer=15
2020-03-31T10:17:50Z received: inv (37 bytes) peer=21
2020-03-31T10:17:50Z got inv: tx bc6099be609e8a81e11b1ba53badd401a3361fe70c8a90dd92cc743ab972b32c  have peer=21
2020-03-31T10:17:50Z received: inv (37 bytes) peer=2
2020-03-31T10:17:50Z got inv: tx bc6099be609e8a81e11b1ba53badd401a3361fe70c8a90dd92cc743ab972b32c  have peer=2
2020-03-31T10:17:50Z libevent: epoll_dispatch: epoll_wait reports 1
2020-03-31T10:17:50Z libevent: event_active: 0x561e681d9d08 (fd 9), res 2, callback 0x7fe4fc82e1b0
2020-03-31T10:17:50Z libevent: event_process_active: event: 0x561e681d9d08, EV_READ   call 0x7fe4fc82e1b0
2020-03-31T10:17:50Z libevent: evhttp_get_request_connection: new request from 10.10.1.10:22443 on 52

2020-03-31T10:17:50Z libevent: Attempting connection to 10.1.1.10:22443

2020-03-31T10:17:50Z libevent: event_add: event: 0x7fe4e0000b60 (fd -1), EV_READ    call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4e0000be0 (fd -1), callback 0x7fe4fc81fb40
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4e0000b60 (fd -1), callback 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4e0000be0 (fd -1), callback 0x7fe4fc81fb40
2020-03-31T10:17:50Z libevent: event_add: event: 0x7fe4e0000b60 (fd 52), EV_READ    call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: Epoll ADD(1) on fd 52 okay. Old events were 0; read change was 1 (add); write change was 0 (none); close change was 0 (none)
2020-03-31T10:17:50Z libevent: event_add: event: 0x7fe4e0000b60 (fd 52), EV_READ   EV_TIMEOUT call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_add: event 0x7fe4e0000b60, timeout in 30 seconds 0 useconds, call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4e0000be0 (fd 52), callback 0x7fe4fc81fb40
2020-03-31T10:17:50Z libevent: event_add: event: 0x7fe4e0000b60 (fd 52), EV_READ   EV_TIMEOUT call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_add: event 0x7fe4e0000b60, timeout in 30 seconds 0 useconds, call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: timeout_next: event: 0x7fe4bc001f90, in 0 seconds, 4053 useconds
2020-03-31T10:17:50Z libevent: epoll_dispatch: epoll_wait reports 1
2020-03-31T10:17:50Z libevent: event_active: 0x7fe4e0000b60 (fd 52), res 2, callback 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_process_active: event: 0x7fe4e0000b60, EV_READ   call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_add: event: 0x7fe4e0000b60 (fd 52), EV_READ   EV_TIMEOUT call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: event_add: event 0x7fe4e0000b60, timeout in 8206112 seconds 564133 useconds, call 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: evhttp_add_header: key: Host val: 10.1.1.5:50000
2020-03-31T10:17:50Z libevent: evhttp_add_header: key: Authorization val: Basic c210L.....dFZnMGE3YVk3MnRGcU9qTzhRVT0=

2020-03-31T10:17:50Z libevent: evhttp_add_header: key: Accept val: */*

2020-03-31T10:17:50Z libevent: evhttp_add_header: key: Content-type val: application/json

2020-03-31T10:17:50Z libevent: evhttp_add_header: key: Content-Length val: 111

2020-03-31T10:17:50Z libevent: evhttp_read_header: checking for post data on 52

2020-03-31T10:17:50Z libevent: evhttp_get_body_length: bytes to read: 111 (in buffer 111)

2020-03-31T10:17:50Z libevent: event_del: 0x7fe4e0000b60 (fd 52), callback 0x7fe4fc81ff40
2020-03-31T10:17:50Z libevent: Epoll DEL(1) on fd 52 okay. Old events were 2; read change was 2 (del); write change was 0 (none); close change was 0 (none)
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4e0000b60 (fd 52), callback 0x7fe4fc81ff40
2020-03-31T10:17:50Z Received a POST request for /wallet/test from 10.1.1.10:22443
2020-03-31T10:17:50Z libevent: timeout_next: event: 0x7fe4bc001f90, in 0 seconds, 4053 useconds
2020-03-31T10:17:50Z ThreadRPCServer method=walletpassphrase user=test
2020-03-31T10:17:50Z libevent: epoll_dispatch: epoll_wait reports 0
2020-03-31T10:17:50Z libevent: timeout_next: event: 0x7fe4bc001f90, in 0 seconds, 4053 useconds
2020-03-31T10:17:50Z libevent: epoll_dispatch: epoll_wait reports 0
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4bc001f90 (fd -1), callback 0x561e66258dd0
2020-03-31T10:17:50Z libevent: timeout_process: event: 0x7fe4bc001f90, call 0x561e66258dd0
2020-03-31T10:17:50Z libevent: event_active: 0x7fe4bc001f90 (fd -1), res 1, callback 0x561e66258dd0
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4bc001f90 (fd -1), callback 0x561e66258dd0
2020-03-31T10:17:50Z libevent: event_process_active: event: 0x7fe4bc001f90,    call 0x561e66258dd0
2020-03-31T10:17:50Z libevent: event_del: 0x7fe4bc001f90 (fd -1), callback 0x561e66258dd0
2020-03-31T10:17:58Z received: ping (8 bytes) peer=109
2020-03-31T10:17:58Z sending pong (8 bytes) peer=109
2020-03-31T10:19:13Z Making feeler connection to [2607:fea8:8460:2b4a::4]:18333
2020-03-31T10:19:13Z trying connection [2607:fea8:8460:2b4a::4]:18333 lastseen=842.8hrs
2020-03-31T10:19:18Z connection to [2607:fea8:8460:2b4a::4]:18333 timeout
2020-03-31T10:20:03Z socket closed
2020-03-31T10:20:03Z disconnecting peer=110
2020-03-31T10:21:10Z Making feeler connection to 54.162.24.231:18333
2020-03-31T10:21:10Z trying connection 54.162.24.231:18333 lastseen=556.7hrs
2020-03-31T10:21:15Z connection to 54.162.24.231:18333 timeout
2020-03-31T10:21:16Z Making feeler connection to 70.24.60.7:18333
2020-03-31T10:21:16Z trying connection 70.24.60.7:18333 lastseen=634.4hrs
2020-03-31T10:21:21Z connection to 70.24.60.7:18333 timeout
2020-03-31T10:21:35Z socket closed
2020-03-31T10:21:35Z disconnecting peer=111

About this issue

  • Original URL
  • State: closed
  • Created 4 years ago
  • Comments: 20 (10 by maintainers)

Commits related to this issue

Most upvoted comments

@promag Thank you! I’m going to build and test the fix Let you know asap