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.

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

unable to start server: historical channel bucket has not yet been created #6155

Closed
brandoncollins7 opened this issue Jan 13, 2022 · 6 comments · Fixed by #6159 · May be fixed by #9653
Closed

unable to start server: historical channel bucket has not yet been created #6155

brandoncollins7 opened this issue Jan 13, 2022 · 6 comments · Fixed by #6159 · May be fixed by #9653
Labels
P2 should be fixed if one has time
Milestone

Comments

@brandoncollins7
Copy link

brandoncollins7 commented Jan 13, 2022

Background

I have an older casa hardware node which I am trying to restore on a local node on my windows machine. Following the instructions here: https://support.keys.casa/hc/en-us/articles/360050420391-Casa-Node-Funds-Recovery-Guide

I synced a fresh bitcoin node with pruning disabled. I then copied my lnd data folder from the casa node to my windows pc and started lnd and ran ./lncli unlock using my casa password. The lnd node unlocks and lnd looks to start successfully syncing.

After a few hours the lnd node seems to just shut down without any clear error other then the title of this post (which I cannot seem to find a single google result for)

Here is a sample of the tail end of the shutdown:

2022-01-13 02:26:13.235 [DBG] CNCT: ChannelArbitrator(95da8976895886749553ac745d18f3f2e4f8ff7477bbd3dba6ae69d0a6ecc215:0): terminating at state=StateDefault
2022-01-13 02:26:13.235 [DBG] CNCT: Starting ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0), htlc_set=(map[contractcourt.HtlcSetKey]contractcourt.htlcSet) (len=2) {
(contractcourt.HtlcSetKey) RemoteHtlcSet: (contractcourt.htlcSet) {
 incomingHTLCs: (map[uint64]channeldb.HTLC) {
 },
 outgoingHTLCs: (map[uint64]channeldb.HTLC) {
 }
},
(contractcourt.HtlcSetKey) LocalHtlcSet: (contractcourt.htlcSet) {
 incomingHTLCs: (map[uint64]channeldb.HTLC) {
 },
 outgoingHTLCs: (map[uint64]channeldb.HTLC) {
 }
}
}
, state=StateDefault
2022-01-13 02:26:13.236 [INF] CNCT: ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=718426
2022-01-13 02:26:13.238 [DBG] CNCT: ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0): attempting state step with trigger=chainTrigger from state=StateDefault
2022-01-13 02:26:13.238 [DBG] CNCT: ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0): new block (height=718426) examining active HTLC's
2022-01-13 02:26:13.238 [DBG] CNCT: ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0): checking commit chain actions at height=718426, in_htlc_count=0, out_htlc_count=0
2022-01-13 02:26:13.238 [TRC] CNCT: ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0): no actions to take at height=718426
2022-01-13 02:26:13.238 [DBG] CNCT: ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0): no actions for chain trigger, terminating
2022-01-13 02:26:13.238 [DBG] CNCT: ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0): terminating at state=StateDefault
2022-01-13 02:26:13.238 [DBG] CNCT: Starting ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1), htlc_set=(map[contractcourt.HtlcSetKey]contractcourt.htlcSet) <nil>
, state=StateWaitingFullResolution
2022-01-13 02:26:13.241 [INF] CNCT: ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1): starting state=StateWaitingFullResolution, trigger=chainTrigger, triggerHeight=576367
2022-01-13 02:26:13.241 [DBG] CNCT: ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1): attempting state step with trigger=chainTrigger from state=StateWaitingFullResolution
2022-01-13 02:26:13.241 [INF] CNCT: ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1): still awaiting contract resolution
2022-01-13 02:26:13.242 [TRC] CNCT: ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1): next_state=StateWaitingFullResolution
2022-01-13 02:26:13.242 [DBG] CNCT: ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1): terminating at state=StateWaitingFullResolution
2022-01-13 02:26:13.242 [INF] CNCT: ChainArbitrator shutting down
2022-01-13 02:26:13.242 [TRC] CNCT: Attempting to stop ChainWatcher(187cc41cddf924966397cdb43959fd54281d43ebeea91d8937e46e0d9747f108:0)
2022-01-13 02:26:13.242 [TRC] CNCT: Attempting to stop ChainWatcher(4050475348f4d2c3d85f63c2f1c1acaa1ebbd8ac0b42ee4177b06ce613112b4c:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(19764670faab792f320d122f2571e6f6cdb5b147f0e0ad155b16f0706684dcc3:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(95da8976895886749553ac745d18f3f2e4f8ff7477bbd3dba6ae69d0a6ecc215:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(19e8d7575369c2190656923b388dc6ea65b7816b853a19060d032b3275117137:1)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(037c186ec20aa36f1ebe6db43213e08945c38ae5f451ddcf113bfa9e080e81ff:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(9ab01a8523e9fdbbff430683643a32ded4fa749765c8bdb91e7dda097b7aca05:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(21b3e4df9be1215e8f77dbe44b23440e91b2cd982d1172571e7b167f4186158c:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChainWatcher(b0c9177a1667c70310906097a193cae5713dd07159efc18bfe99ce5cebaa5053:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChannelArbitrator(9ab01a8523e9fdbbff430683643a32ded4fa749765c8bdb91e7dda097b7aca05:0)
2022-01-13 02:26:13.243 [DBG] CNCT: Stopping ChannelArbitrator(9ab01a8523e9fdbbff430683643a32ded4fa749765c8bdb91e7dda097b7aca05:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChannelArbitrator(b0c9177a1667c70310906097a193cae5713dd07159efc18bfe99ce5cebaa5053:0)
2022-01-13 02:26:13.243 [DBG] CNCT: Stopping ChannelArbitrator(b0c9177a1667c70310906097a193cae5713dd07159efc18bfe99ce5cebaa5053:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChannelArbitrator(037c186ec20aa36f1ebe6db43213e08945c38ae5f451ddcf113bfa9e080e81ff:0)
2022-01-13 02:26:13.243 [DBG] CNCT: Stopping ChannelArbitrator(037c186ec20aa36f1ebe6db43213e08945c38ae5f451ddcf113bfa9e080e81ff:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChannelArbitrator(187cc41cddf924966397cdb43959fd54281d43ebeea91d8937e46e0d9747f108:0)
2022-01-13 02:26:13.243 [DBG] CNCT: Stopping ChannelArbitrator(187cc41cddf924966397cdb43959fd54281d43ebeea91d8937e46e0d9747f108:0)
2022-01-13 02:26:13.243 [TRC] CNCT: Attempting to stop ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1)
2022-01-13 02:26:13.243 [DBG] CNCT: Stopping ChannelArbitrator(fdd0ed5083bd889a5297f95903721b2ed2a977bca7f6f6a67a806e17fa47d644:1)
2022-01-13 02:26:13.244 [TRC] CNCT: Attempting to stop ChannelArbitrator(19764670faab792f320d122f2571e6f6cdb5b147f0e0ad155b16f0706684dcc3:0)
2022-01-13 02:26:13.244 [DBG] CNCT: Stopping ChannelArbitrator(19764670faab792f320d122f2571e6f6cdb5b147f0e0ad155b16f0706684dcc3:0)
2022-01-13 02:26:13.244 [TRC] CNCT: Attempting to stop ChannelArbitrator(21b3e4df9be1215e8f77dbe44b23440e91b2cd982d1172571e7b167f4186158c:0)
2022-01-13 02:26:13.244 [DBG] CNCT: Stopping ChannelArbitrator(21b3e4df9be1215e8f77dbe44b23440e91b2cd982d1172571e7b167f4186158c:0)
2022-01-13 02:26:13.244 [TRC] CNCT: Attempting to stop ChannelArbitrator(4050475348f4d2c3d85f63c2f1c1acaa1ebbd8ac0b42ee4177b06ce613112b4c:0)
2022-01-13 02:26:13.244 [DBG] CNCT: Stopping ChannelArbitrator(4050475348f4d2c3d85f63c2f1c1acaa1ebbd8ac0b42ee4177b06ce613112b4c:0)
2022-01-13 02:26:13.244 [TRC] CNCT: Attempting to stop ChannelArbitrator(95da8976895886749553ac745d18f3f2e4f8ff7477bbd3dba6ae69d0a6ecc215:0)
2022-01-13 02:26:13.244 [DBG] CNCT: Stopping ChannelArbitrator(95da8976895886749553ac745d18f3f2e4f8ff7477bbd3dba6ae69d0a6ecc215:0)
2022-01-13 02:26:13.244 [TRC] CNCT: Attempting to stop ChannelArbitrator(19e8d7575369c2190656923b388dc6ea65b7816b853a19060d032b3275117137:1)
2022-01-13 02:26:13.244 [DBG] CNCT: Stopping ChannelArbitrator(19e8d7575369c2190656923b388dc6ea65b7816b853a19060d032b3275117137:1)
2022-01-13 02:26:13.244 [TRC] CNCT: Attempting to stop ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0)
2022-01-13 02:26:13.244 [DBG] CNCT: Stopping ChannelArbitrator(50b2f25450a1b05422cd6540281c515ab8775b21c128092f38cc8a857fe1398c:0)
2022-01-13 02:26:13.244 [INF] FNDG: Funding manager shutting down
2022-01-13 02:26:13.244 [INF] BRAR: Breach arbiter shutting down
2022-01-13 02:26:13.244 [INF] UTXN: UTXO nursery shutting down
2022-01-13 02:26:13.244 [INF] NTFN: Cancelling epoch notification, epoch_id=2
2022-01-13 02:26:13.244 [INF] SWPR: Sweeper shutting down
2022-01-13 02:26:13.244 [INF] NTFN: Cancelling epoch notification, epoch_id=1
2022-01-13 02:26:13.245 [DBG] SWPR: Sweeper shut down
2022-01-13 02:26:13.245 [INF] HSWC: HtlcNotifier shutting down
2022-01-13 02:26:13.245 [INF] PRNF: PeerNotifier shutting down
2022-01-13 02:26:13.245 [INF] CHNF: ChannelNotifier shutting down
2022-01-13 02:26:13.245 [INF] NTFN: bitcoind notifier shutting down
2022-01-13 02:26:13.257 [ERR] NTFN: Rescan to determine the spend details of outpoint=19e8d7575369c2190656923b388dc6ea65b7816b853a19060d032b3275117137:1, script=0 3bc0e4848649c89df424213218599b62a7f5fa1240a135a47e69672edc8e9729 within range 647565-718426 failed: chain notifier shutting down
2022-01-13 02:26:13.257 [ERR] NTFN: Rescan to determine the spend details of outpoint=4050475348f4d2c3d85f63c2f1c1acaa1ebbd8ac0b42ee4177b06ce613112b4c:0, script=0 31a1992ac5e35488d0c16f18351d538e594a2fa20a0db714ee1a34423a961e9a within range 647565-718426 failed: chain notifier shutting down
2022-01-13 02:26:13.257 [ERR] NTFN: Rescan to determine the spend details of outpoint=95da8976895886749553ac745d18f3f2e4f8ff7477bbd3dba6ae69d0a6ecc215:0, script=0 db0726ffe9b3c9ae1cc99fd47358578980d9ace72e09c32b69b8ca621d4fb153 within range 647565-718426 failed: chain notifier shutting down
2022-01-13 02:26:13.257 [ERR] NTFN: Rescan to determine the spend details of outpoint=19764670faab792f320d122f2571e6f6cdb5b147f0e0ad155b16f0706684dcc3:0, script=0 9ce006f1763a8dd3b291fa86b6b83be8fd94ee34c3c957c90de96c82c43a4d62 within range 647565-718426 failed: chain notifier shutting down
2022-01-13 02:26:13.257 [ERR] NTFN: Rescan to determine the spend details of outpoint=b0c9177a1667c70310906097a193cae5713dd07159efc18bfe99ce5cebaa5053:0, script=0 a2f2f175e696f995dcf85a1d901e2f3cda903b3aeaded4e927f41d09cec0e8bc within range 647565-718426 failed: chain notifier shutting down
2022-01-13 02:26:13.257 [ERR] NTFN: Rescan to determine the spend details of outpoint=037c186ec20aa36f1ebe6db43213e08945c38ae5f451ddcf113bfa9e080e81ff:0, script=0 96c3dd14e4c1006adeb09637a4425e77c6192999fb11ec13517156a3ddffa503 within range 647565-718426 failed: chain notifier shutting down
2022-01-13 02:26:13.257 [INF] HLCK: Health monitor shutting down
2022-01-13 02:26:13.257 [DBG] HLCK: Health check: monitor quit
2022-01-13 02:26:13.257 [ERR] LTND: Shutting down because error in main method: unable to start server: historical channel bucket has not yet been created
2022-01-13 02:26:13.258 [INF] RPCS: Stopping RPC Server
2022-01-13 02:26:13.258 [INF] RPCS: Stopping WatchtowerRPC Sub-RPC Server
2022-01-13 02:26:13.258 [INF] RPCS: Stopping SignRPC Sub-RPC Server
2022-01-13 02:26:13.258 [INF] RPCS: Stopping RouterRPC Sub-RPC Server
2022-01-13 02:26:13.258 [INF] RPCS: Stopping AutopilotRPC Sub-RPC Server
2022-01-13 02:26:13.259 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server
2022-01-13 02:26:13.259 [INF] RPCS: Stopping VersionRPC Sub-RPC Server
2022-01-13 02:26:13.259 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server
2022-01-13 02:26:13.259 [INF] RPCS: Stopping ChainRPC Sub-RPC Server
2022-01-13 02:26:13.259 [INF] RPCS: Stopping WatchtowerClientRPC Sub-RPC Server
2022-01-13 02:26:13.265 [INF] LTND: Shutdown complete

unable to start server: historical channel bucket has not yet been created

I also tried the recovery method by deleting the wallet.db file and reinitializing the wallet using lncli create and my seed. It successfully entered recovery mode, began syncing for a few hours and then eventually shut down with the exact same error.

Your environment

  • lnd version 0.14.1-beta commit=v0.14.1-beta
  • Windows 10
  • bitcoind v22.0.0

Steps to reproduce

Steps above

Expected behaviour

lnd should sync and allow me to access my funds

Actual behaviour

Shutdown and crash with error: "unable to start server: historical channel bucket has not yet been created"

@guggero
Copy link
Collaborator

guggero commented Jan 13, 2022

I looked at where this error is coming from and it seems like there was an oversight in the last DB migration. This only seems to happen if you skip a few versions.

I have a simple patch that should allow you to start up. Can you try if that fixes the problem for you while we work on a more permanent fix?

This should allow you to compile a version of lnd with the patch:

git clone https://github.com/lightningnetwork/lnd
git checkout v0.14.1-beta
git apply <patch-file>
make release-install

Here's the patch file:
historical-channel-bucket.txt

@brandoncollins7
Copy link
Author

Thanks, today I actually tried going back to v13 and it is currently resyncing... hasn't hit an issue yet. Once that is done I will retry with a backup of my db. Although I am not sure if I have all the tools to run make on my windows machine? I am just using compiled binaries.

@Roasbeef Roasbeef added this to the v0.14.2 milestone Jan 13, 2022
@brandoncollins7
Copy link
Author

looks like I was able to catch up to latest block and then switch to 14 and it hasn't crashed yet

@Roasbeef
Copy link
Member

I looked at where this error is coming from and it seems like there was an oversight in the last DB migration. This only seems to happen if you skip a few versions.

Is is the migration or just that this node didn't have the contents of the historical bucket at all, since it was a few years old?

See this PR: #6159

@Roasbeef
Copy link
Member

Ah I see the solution in the patch file now:

diff --git a/channeldb/db.go b/channeldb/db.go
index 1b56d3de3..f93befd51 100644
--- a/channeldb/db.go
+++ b/channeldb/db.go
@@ -353,9 +353,14 @@ func (d *DB) Wipe() error {
 // the database are created.
 func initChannelDB(db kvdb.Backend) error {
 	err := kvdb.Update(db, func(tx kvdb.RwTx) error {
+		_, err := tx.CreateTopLevelBucket(historicalChannelBucket)
+		if err != nil {
+			return err
+		}
+
 		meta := &Meta{}
 		// Check if DB is already initialized.
-		err := fetchMeta(meta, tx)
+		err = fetchMeta(meta, tx)
 		if err == nil {
 			return nil
 		}

I think ensuring it always exists is better than handling this special case. In the end, the behavior will be the same (it'll return chan not found instead).

@Roasbeef
Copy link
Member

I think we actually also want this as well:

diff --git a/channeldb/db.go b/channeldb/db.go
index 92a49c2f8..2ad2803da 100644
--- a/channeldb/db.go
+++ b/channeldb/db.go
@@ -329,6 +329,7 @@ var dbTopLevelBuckets = [][]byte{
        metaBucket,
        closeSummaryBucket,
        outpointBucket,
+       historicalChannelBucket,
 }

When a channel is closed we use CreateBucketIfNotExists, which means users that close a channel will eventually have this created...also the contract court won't query for this information unless a channel is closed.

@HannahMR HannahMR added the P2 should be fixed if one has time label Jan 17, 2022
Roasbeef added a commit to Roasbeef/lnd that referenced this issue Jan 18, 2022
For older nodes, this bucket was never created, so we'll get an error if
we try and query it. In this commit, we catch this error like we do when
a given channel doesn't have the information (but the bucket actually
exists).

Fixes lightningnetwork#6155
Roasbeef added a commit to Roasbeef/lnd that referenced this issue Jan 26, 2022
For older nodes, this bucket was never created, so we'll get an error if
we try and query it. In this commit, we catch this error like we do when
a given channel doesn't have the information (but the bucket actually
exists).

Fixes lightningnetwork#6155
matheusd pushed a commit to matheusd/dcrlnd that referenced this issue Feb 12, 2024
For older nodes, this bucket was never created, so we'll get an error if
we try and query it. In this commit, we catch this error like we do when
a given channel doesn't have the information (but the bucket actually
exists).

Fixes lightningnetwork#6155
matheusd pushed a commit to matheusd/dcrlnd that referenced this issue Feb 22, 2024
For older nodes, this bucket was never created, so we'll get an error if
we try and query it. In this commit, we catch this error like we do when
a given channel doesn't have the information (but the bucket actually
exists).

Fixes lightningnetwork#6155
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
P2 should be fixed if one has time
Projects
None yet
4 participants