search

lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.69k stars 2.08k forks source link

[bug]: LND crashes while starting up #9065

Closed sonnenstreifen closed 2 months ago

sonnenstreifen commented 2 months ago

Background

Since a power outage a few weeks ago LND keeps crashing right after startup.

Your environment

Steps to reproduce

Crashes right after startup

Expected behaviour

It should watch my channels and let me spend satoshis :-)

Actual behaviour

See Stacktrace

Stacktrace

Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.146 [INF] LTND: Version: 0.18.3-beta.rc2 commit=v0.18.3-beta.rc2, build=production, logging=default, debuglevel=debug
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.146 [INF] LTND: Active chain: Bitcoin (network=mainnet)
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.148 [DBG] ARPC: Autopilot RPC server successfully register with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.148 [DBG] NTFR: ChainNotifier RPC server successfully register with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] NTFR: ChainKit RPC server successfully register with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] NRPC: Neutrino RPC server successfully register with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] PRPC: Peers RPC server successfully register with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] SGNR: Signer RPC server successfully register with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] VRPC: Versioner RPC server successfully registered with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] WLKT: WalletKit RPC server successfully registered with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] IRPC: Invoices RPC server successfully registered with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [DBG] RRPC: Router RPC server successfully register with root gRPC server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.149 [INF] RPCS: RPC server listening on 0.0.0.0:10009
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.152 [DBG] ARPC: Autopilot REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.152 [DBG] NTFR: ChainNotifier REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.153 [DBG] NTFR: ChainKit REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.155 [DBG] NRPC: Neutrino REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.156 [DBG] PRPC: Peers REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.160 [DBG] SGNR: Signer REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.162 [DBG] VRPC: Versioner REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.163 [DBG] WLKT: WalletKit REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.165 [DBG] IRPC: Invoices REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.167 [DBG] RRPC: Router REST server successfully registered with root REST server
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.169 [INF] RPCS: gRPC proxy started at 0.0.0.0:8080
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.170 [INF] LTND: Opening the main database, this might take a few minutes...
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.170 [INF] LTND: Opening bbolt database, sync_freelist=true, auto_compact=true
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.171 [INF] CHDB: Compacting database file at /home/lnd/.lnd/data/graph/mainnet/channel.db
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.172 [DBG] CHDB: Free disk space on compaction destination file system: 1113706491904 bytes
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.176 [DBG] CHDB: Compacting top level bucket 'alias-bucket'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.177 [DBG] CHDB: Compacting top level bucket 'base-bucket'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.178 [DBG] CHDB: Compacting top level bucket 'byte'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.178 [DBG] CHDB: Compacting top level bucket 'chan-id-bucket'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.179 [DBG] CHDB: Compacting top level bucket 'channelOpeningState'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.180 [DBG] CHDB: Compacting top level bucket 'circuit-adds'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.180 [DBG] CHDB: Compacting top level bucket 'circuit-fwd-log'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.182 [DBG] CHDB: Compacting top level bucket 'circuit-keystones'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.183 [DBG] CHDB: Compacting top level bucket 'close-summaries'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.184 [DBG] CHDB: Compacting top level bucket 'closed-chan-bucket'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.186 [DBG] CHDB: Compacting top level bucket 'confirm-hints'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.190 [DBG] CHDB: Compacting top level bucket 'edge-index'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.190 [DBG] CHDB: Compacting top level bucket 'fwd-packages'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.191 [DBG] CHDB: Compacting top level bucket 'graph-edge'
Sep 04 20:20:18 lightningnode lnd[1613699]: 2024-09-04 20:20:18.302 [INF] LTND: Shutdown complete
Sep 04 20:20:18 lightningnode lnd[1613699]: panic: runtime error: invalid memory address or nil pointer dereference
Sep 04 20:20:18 lightningnode lnd[1613699]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x10f82a8]
Sep 04 20:20:18 lightningnode lnd[1613699]: goroutine 1 [running]:
Sep 04 20:20:18 lightningnode lnd[1613699]: go.etcd.io/bbolt.(*Bucket).Sequence(...)
Sep 04 20:20:18 lightningnode lnd[1613699]:         go.etcd.io/bbolt@v1.3.7/bucket.go:338
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.(*compacter).walkBucket.func1({0x7f348af1d0, 0xc, 0xc}, {0x0?, 0x40005542d0?, 0x1?})
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/bolt_compact.go:277 +0xb8
Sep 04 20:20:18 lightningnode lnd[1613699]: go.etcd.io/bbolt.(*Bucket).ForEach(0x0?, 0x4000a98520)
Sep 04 20:20:18 lightningnode lnd[1613699]:         go.etcd.io/bbolt@v1.3.7/bucket.go:389 +0xc0
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.(*compacter).walkBucket(0x4000a98b78, 0x4000556680, {0x0, 0x0, 0x0}, {0x7f348af3ac, 0xa, 0xa}, {0x0, 0x10?, ...}, ...)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/bolt_compact.go:273 +0x14c
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.(*compacter).compact.(*compacter).walk.func3.1({0x7f348af3ac, 0xa, 0xa}, 0x4000556680)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/bolt_compact.go:226 +0x104
Sep 04 20:20:18 lightningnode lnd[1613699]: go.etcd.io/bbolt.(*Tx).ForEach.func1({0x7f348af3ac, 0xa, 0xa}, {0x400011a9d8?, 0x40004fa6f8?, 0x65e050?})
Sep 04 20:20:18 lightningnode lnd[1613699]:         go.etcd.io/bbolt@v1.3.7/tx.go:130 +0x68
Sep 04 20:20:18 lightningnode lnd[1613699]: go.etcd.io/bbolt.(*Bucket).ForEach(0x4000188500?, 0x4000a986c0)
Sep 04 20:20:18 lightningnode lnd[1613699]:         go.etcd.io/bbolt@v1.3.7/bucket.go:389 +0xc0
Sep 04 20:20:18 lightningnode lnd[1613699]: go.etcd.io/bbolt.(*Tx).ForEach(0x40004fa768?, 0x400070cf48?)
Sep 04 20:20:18 lightningnode lnd[1613699]:         go.etcd.io/bbolt@v1.3.7/tx.go:129 +0x44
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.(*compacter).compact.(*compacter).walk.func3(0x4000408000?)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/bolt_compact.go:220 +0x44
Sep 04 20:20:18 lightningnode lnd[1613699]: go.etcd.io/bbolt.(*DB).View(0xdf8475800?, 0x40004fa828)
Sep 04 20:20:18 lightningnode lnd[1613699]:         go.etcd.io/bbolt@v1.3.7/db.go:893 +0x70
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.(*compacter).walk(...)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/bolt_compact.go:219
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.(*compacter).compact(0x40004fab78, 0x400070cfc8, 0x400070cd88)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/bolt_compact.go:147 +0xe8
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.(*compacter).execute(0x4000a98b78)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/bolt_compact.go:117 +0x41c
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.compactAndSwap(0x40004fb158)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/backend.go:178 +0x560
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/kvdb.GetBoltBackend(0x4000a99158)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/kvdb@v1.4.10/backend.go:100 +0x74
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd/lncfg.(*DB).GetBackends(0x400024aa40, {0x2036790, 0x40001980f0}, {0x40008946c0, 0x21}, {0x4000301380, 0x29}, {0x40008946f0, 0x2e}, 0x0, ...)
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/lncfg/db.go:622 +0x2a1c
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd.(*DefaultDatabaseBuilder).BuildDatabase(0x400000c4f8, {0x2036790, 0x40001980f0})
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/config_builder.go:927 +0x240
Sep 04 20:20:18 lightningnode lnd[1613699]: github.com/lightningnetwork/lnd.Main(0x40004ceb08, {{0x0?, 0x40003960c0?, 0x4000396120?}}, 0x4000282540, {0x40001e8600, 0x40003960c0, 0x4000396120, 0x4000396180, {0x0}})
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/lnd.go:447 +0x17e4
Sep 04 20:20:18 lightningnode lnd[1613699]: main.main()
Sep 04 20:20:18 lightningnode lnd[1613699]:         github.com/lightningnetwork/lnd/cmd/lnd/main.go:38 +0x198
Sep 04 20:20:18 lightningnode systemd[1]: lnd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Sep 04 20:20:18 lightningnode systemd[1]: lnd.service: Failed with result 'exit-code'.
ziggie1984 commented 2 months ago

Unfortunately during your crash the database of LND (channel.db) corrupted. You could play a forensic (advanced) and figure out which part of the db corrupted and drop the related bucket form the db, but it's very likely that a top-level bucket got corrupted and hence there is no other possibility then initiating a SCB.

More information here: https://docs.lightning.engineering/lightning-network-tools/lnd/disaster-recovery

saubyk commented 2 months ago

For future reference, if you're running a node with reasonable amount of funds, make sure you have a power backup so that power failures do no result in disk failures and database corruption