search

ElementsProject / elements

Open Source implementation of advanced blockchain features extending the Bitcoin protocol
MIT License
1.07k stars 381 forks source link

`bad optional access` error at startup #1334

Closed rachyandco closed 2 months ago

rachyandco commented 6 months ago

Elementsd is at "Pruning blockstore" and shutdown after a EXCEPTION: St19bad_optional_access or bad optional access error at startup.

Expected behavior

Node should sync.

Actual behavior

Fails at prunning blockstore and reboots.

To reproduce

This is an elemenstd running inside a docker within a BTCPayServer setup. The following instruction were done https://github.com/btcpayserver/btcpayserver/issues/1282

System information

ubuntu 22.04, Docker version 26.1.3, build b72abbb

v23.2.1 inside a docker.

VPS with 32G mem, 4G swap, 8 core machine with more than 100G free disk space.

logs: 

2024-05-26T14:30:26Z Elements Core version v23.2.1 (release build)
2024-05-26T14:30:26Z Validating signatures for all blocks.
2024-05-26T14:30:26Z Setting nMinimumChainWork=0000000000000000000000000000000000000000000000000000000000000000
2024-05-26T14:30:26Z Prune configured to target 5000 MiB on disk for block and undo files.
2024-05-26T14:30:26Z Configured for header-trimming mode. This will reduce memory usage substantially, but we will be unable to serve as a full P2P peer, and certain header fields may be missing from JSON RPC output.
2024-05-26T14:30:26Z Using the 'sse4(1way),sse41(4way),avx2(8way)' SHA256 implementation
2024-05-26T14:30:26Z Using RdSeed as additional entropy source
2024-05-26T14:30:26Z Using RdRand as an additional entropy source
2024-05-26T14:30:26Z Default data directory /home/elements/.elements
2024-05-26T14:30:26Z Using data directory /home/elements/.elements/liquidv1
2024-05-26T14:30:26Z Config file: /home/elements/.elements/elements.conf
2024-05-26T14:30:26Z Config file arg: chain="liquidv1"
2024-05-26T14:30:26Z Config file arg: [liquidv1] fallbackfee="0.000001"
2024-05-26T14:30:26Z Config file arg: [liquidv1] port="39388"
2024-05-26T14:30:26Z Config file arg: [liquidv1] printtoconsole="1"
2024-05-26T14:30:26Z Config file arg: [liquidv1] prune="5000"
2024-05-26T14:30:26Z Config file arg: [liquidv1] rpcallowip="::/0"
2024-05-26T14:30:26Z Config file arg: [liquidv1] rpcallowip="0.0.0.0/0"
2024-05-26T14:30:26Z Config file arg: [liquidv1] rpcauth=****
2024-05-26T14:30:26Z Config file arg: [liquidv1] rpcbind=****
2024-05-26T14:30:26Z Config file arg: [liquidv1] rpcport="43782"
2024-05-26T14:30:26Z Config file arg: [liquidv1] trim_headers="1"
2024-05-26T14:30:26Z Config file arg: [liquidv1] validatepegin="0"
2024-05-26T14:30:26Z Config file arg: [liquidv1] walletdir="/walletdata/liquidv1/liquidv1/wallets"
2024-05-26T14:30:26Z Config file arg: [liquidv1] whitelist="0.0.0.0/0"
2024-05-26T14:30:26Z Using at most 125 automatic connections (1048576 file descriptors available)
2024-05-26T14:30:27Z Using 8 MiB out of 16/4 requested for signature cache, able to store 262144 elements
2024-05-26T14:30:27Z Using 8 MiB out of 16/4 requested for script execution cache, able to store 262144 elements
2024-05-26T14:30:27Z Using 8 MiB out of 8/4 requested for rangeproof cache, able to store 262144 elements
2024-05-26T14:30:27Z Using 8 MiB out of 8/4 requested for surjectionproof cache, able to store 262144 elements
2024-05-26T14:30:27Z Script verification uses 7 additional threads
2024-05-26T14:30:27Z scheduler thread start
2024-05-26T14:30:27Z WARNING: the RPC server is not safe to expose to untrusted networks such as the public internet
2024-05-26T14:30:27Z HTTP: creating work queue of depth 16
2024-05-26T14:30:27Z Using random cookie authentication.
2024-05-26T14:30:27Z Generated RPC authentication cookie /home/elements/.elements/liquidv1/.cookie
2024-05-26T14:30:27Z Using rpcauth authentication.
2024-05-26T14:30:27Z HTTP: starting 4 worker threads
2024-05-26T14:30:27Z Using wallet directory /walletdata/liquidv1/liquidv1/wallets
2024-05-26T14:30:27Z init message: Verifying wallet(s)…
2024-05-26T14:30:27Z Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2024-05-26T14:30:27Z Using wallet /walletdata/liquidv1/liquidv1/wallets/wallet.dat
2024-05-26T14:30:27Z BerkeleyEnvironment::Open: LogDir=/walletdata/liquidv1/liquidv1/wallets/database ErrorFile=/walletdata/liquidv1/liquidv1/wallets/db.log
2024-05-26T14:30:27Z Using /16 prefix for IP bucketing
2024-05-26T14:30:27Z init message: Loading P2P addresses…
2024-05-26T14:30:27Z Loaded 3381 addresses from peers.dat  22ms
2024-05-26T14:30:27Z init message: Loading banlist…
2024-05-26T14:30:27Z SetNetworkActive: true
2024-05-26T14:30:27Z Cache configuration:
2024-05-26T14:30:27Z * Using 2.0 MiB for block index database
2024-05-26T14:30:27Z * Using 8.0 MiB for chain state database
2024-05-26T14:30:27Z * Using 440.0 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
2024-05-26T14:30:27Z init message: Loading block index…
2024-05-26T14:30:27Z Switching active chainstate to Chainstate [ibd] @ height -1 (null)
2024-05-26T14:30:27Z Opening LevelDB in /home/elements/.elements/liquidv1/blocks/index
2024-05-26T14:30:27Z Opened LevelDB successfully
2024-05-26T14:30:27Z Using obfuscation key for /home/elements/.elements/liquidv1/blocks/index: 0000000000000000
2024-05-26T14:31:10Z LoadBlockIndexGuts: loaded 2868048 total / 121475 untrimmed (fully in-memory) headers
2024-05-26T14:31:14Z LoadBlockIndexDB: last block file = 153
2024-05-26T14:31:14Z LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=14445, size=116790015, heights=2853603...2868047, time=2024-05-13...2024-05-23)
2024-05-26T14:31:14Z Checking all blk files are present...
2024-05-26T14:31:15Z LoadBlockIndexDB(): Block files have previously been pruned
2024-05-26T14:31:15Z Opening LevelDB in /home/elements/.elements/liquidv1/chainstate
2024-05-26T14:31:15Z Opened LevelDB successfully
2024-05-26T14:31:15Z Using obfuscation key for /home/elements/.elements/liquidv1/chainstate: 1cbe948b6347bb4f
2024-05-26T14:31:15Z Upgrading utxo-set database...
2024-05-26T14:31:15Z [0%]...[DONE].
2024-05-26T14:31:17Z Loaded best chain: hashBestChain=ef77a4be153a821109139519b2898753bf06e5374e0faacd565f3b2de00a82ec height=2868047 date=2024-05-23T05:03:08Z progress=0.999000
2024-05-26T14:31:17Z init message: Verifying blocks…
2024-05-26T14:31:17Z Verifying last 6 blocks at level 3
2024-05-26T14:31:17Z [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
2024-05-26T14:31:17Z No coin database inconsistencies in last 6 blocks (9 transactions)
2024-05-26T14:31:17Z  block index           50653ms
2024-05-26T14:31:17Z init message: Loading wallet…
2024-05-26T14:31:17Z BerkeleyEnvironment::Open: LogDir=/walletdata/liquidv1/liquidv1/wallets/database ErrorFile=/walletdata/liquidv1/liquidv1/wallets/db.log
2024-05-26T14:31:17Z [default wallet] Wallet File Version = 139900
2024-05-26T14:31:17Z [default wallet] Keys: 2001 plaintext, 0 encrypted, 2001 w/ metadata, 2001 total. Unknown wallet records: 0
2024-05-26T14:31:17Z [default wallet] Wallet completed loading in              32ms
2024-05-26T14:31:17Z [default wallet] setKeyPool.size() = 2000
2024-05-26T14:31:17Z [default wallet] mapWallet.size() = 0
2024-05-26T14:31:17Z [default wallet] m_address_book.size() = 0
2024-05-26T14:31:17Z Unsetting NODE_NETWORK on prune mode
2024-05-26T14:31:17Z init message: Pruning blockstore…

************************
EXCEPTION: St19bad_optional_access       
bad optional access       
bitcoin in AppInit()       

2024-05-26T14:31:20Z 

************************
EXCEPTION: St19bad_optional_access       
bad optional access       
bitcoin in AppInit()       

2024-05-26T14:31:20Z Shutdown: In progress...
2024-05-26T14:31:20Z scheduler thread exit
2024-05-26T14:31:20Z Flushing block index, trimming headers, setTrimmableBlockIndex.size(): 0
2024-05-26T14:31:20Z Flushing block index, trimming headers, setTrimmableBlockIndex.size(): 0
2024-05-26T14:31:20Z [default wallet] Releasing wallet
2024-05-26T14:31:23Z Shutdown: done
delta1 commented 6 months ago

hey thanks for reporting

Configured for header-trimming mode.

This is a known issue when trim_headers and prune are used together, and will be fixed by #1270 in the next release

I think you have enough memory to switch off trim_headers which should resolve your issue

rachyandco commented 5 months ago

This is a known issue when trim_headers and prune are used together, and will be fixed by #1270 in the next release

is there a known date for the next release that includes this fix?

delta1 commented 5 months ago

@rachyandco not yet, but the release candidate is in testing if you'd like to use that for now it's likely to be the same as the release version

https://github.com/delta1/elements-guix-build/releases/tag/elements-23.2.2rc2

ndeet commented 2 months ago

This issue can be closed, the fix for trim_headers works and we upgraded BTCPay elementsd image to 23.2.3 and it works again. Thank you very much for the fix.

https://github.com/btcpayserver/btcpayserver-docker/issues/912#issuecomment-2355129992

delta1 commented 2 months ago

Fix included in 23.2.2 and upwards

https://github.com/ElementsProject/elements/releases