Trouble with macaroons, bucket and database after 0.4.0 to 0.12.0 upgrade

[DebugSlug]

Background

Last time my node ran was around May 22, 2018. v0.4.0. I was trying to upgrade on my own but I think I've dug myself into a hole I can't get out of myself. I went off of Stadicus guide to build my node and it's on a odroid. The first problem was after I upgraded to 0.11.0. from 0.4.0. I couldn't get my macaroons to generate into the new location. I followed some suggestions in this post #890

Your environment

LND from 0.4.0 to 0.11.0 to 0.12.0

DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=16.04
DISTRIB_CODENAME=xenial
DISTRIB_DESCRIPTION="Ubuntu 16.04.4 LTS"
NAME="Ubuntu"
VERSION="16.04.4 LTS (Xenial Xerus)"
ID=ubuntu
ID_LIKE=debian

bitcoind ver 20.1

Expected behaviour

Upgrading to 0.11.0 or 0.12.0 from 0.4.0 should recreate macaroons in new location and LND should reconnect and work.

Actual behaviour

LND does not recreate new macaroons in new location and everything I've tried in the post above hasn't worked. After upgrading from LND 0.4.0, when in LND version 0.11.0 I've tried :

• starting lnd with --no-macaroons and restarting without --no-macaroons
• delete macaroons.db
• Start lnd, create wallet with password with lncli create using my existing wallet password, cipher seed and cipher password - output is : wallet already exists
• Tried wrong password - output is : [lncli] rpc error: code = Unknown desc = failed to delete locked outputs bucket: bucket not found
• Tried deleting tls.cert and tls.key
• macaroons can't be in testnet directories, never was a testnet setup.

Then I upgraded to 0.12.0 to see if anything changes. Now in 0.12.0:

• When I try to run lnd it will shutdown and the output is:

[INF] LTND: Opening bbolt database, sync_freelist=false, auto_compact=false

2021-02-08 20:35:25.223 [INF] LTND: Shutdown complete

unable to open databases: unable to obtain database backends: timeout

I just can't seem to be getting anywhere with it. I admit, I'm not the best at this but I've tried everything I was able to find on this topic. Should I just backup my wallet.db, delete the entire LND directory, and try to get my wallet restored on chain? Would that set the steps in motion to create macaroons since no previous wallet.db is present? I've checked the stats on my node at 1mil and the channels have been closed 2 years ago so funds being stuck shouldn't be a problem.

I'm clueless where to go from here and would greatly appreciate some help with my situation.

[guggero]

It looks like your macaroons aren't created because lnd isn't even able to start up to the point where it would create them.
Can you try this please:

• Make sure only one instance of lnd is running (the unable to obtain database backends: timeout sounds like another process is locking the database).
• Start lnd and observe the log. It should run through some database migrations and then prompt you to unlock the wallet.

If that doesn't work then please post the log and your current configuration file.

[smalla]

Hi,

I do have a very same problem, upgrading from 0.4.0 to 0.12.0, just my node was running till may the 10th :)

These are my logs:
2021-02-14 09:19:35.343 [INF] LTND: Waiting for wallet encryption password. Use lncli create to create a wallet, lncli unlock to unlock an existing wallet, or lncli changepassword to change the password of an existing wallet and unlock it.
2021-02-14 09:19:49.901 [INF] LNWL: Applying wallet transaction manager migration #2
2021-02-14 09:19:49.901 [INF] LNWL: Dropping wallet transaction history
2021-02-14 09:19:49.901 [ERR] LNWL: Unable to apply wallet transaction manager migration #2: failed to delete locked outputs bucket: bucket not found

Any help would be appreciated.
I tried an on chain recovery already with window of 250000, without luck, maybe need a higher window.

Thanks.

[smalla]

restored from backup, and tried another startup:

2021-02-14 09:57:51.660 [INF] LTND: Version: 0.12.0-beta commit=v0.12.0-beta-71-g5cec468f-dirty, build=production, logging=default, debuglevel=info
2021-02-14 09:57:51.660 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2021-02-14 09:57:51.660 [INF] LTND: Opening the main database, this might take a few minutes...
2021-02-14 09:57:51.660 [INF] LTND: Opening bbolt database, sync_freelist=false, auto_compact=false
2021-02-14 09:57:51.662 [INF] CHDB: Checking for schema update: latest_version=20, db_version=0
2021-02-14 09:57:51.662 [INF] CHDB: Performing database schema migration
2021-02-14 09:57:51.662 [INF] CHDB: Applying migration #1
2021-02-14 09:57:51.662 [INF] CHDB: Populating new node update index bucket
2021-02-14 09:57:51.675 [INF] CHDB: Populating new edge update index bucket
2021-02-14 09:57:52.135 [INF] CHDB: Migration to node and edge update indexes complete!
2021-02-14 09:57:52.135 [INF] CHDB: Applying migration #2
2021-02-14 09:57:52.135 [INF] CHDB: Migrating invoice database to new time series format
2021-02-14 09:57:52.135 [INF] CHDB: Migration to invoice time series index complete!
2021-02-14 09:57:52.135 [INF] CHDB: Applying migration #3
2021-02-14 09:57:52.135 [INF] CHDB: Applying migration #4
2021-02-14 09:57:52.307 [INF] CHDB: Migration of edge policies complete!
2021-02-14 09:57:52.307 [INF] CHDB: Applying migration #5
2021-02-14 09:57:52.307 [INF] CHDB: Migrating database to support payment statuses
2021-02-14 09:57:52.307 [INF] CHDB: Marking all known circuits with status InFlight
2021-02-14 09:57:52.307 [INF] CHDB: Marking all existing payments with status Completed
2021-02-14 09:57:52.307 [INF] CHDB: Applying migration #6
2021-02-14 09:57:52.307 [INF] CHDB: Migrating database to properly prune edge update index
2021-02-14 09:57:52.310 [INF] CHDB: Constructing set of edge update entries to purge.
2021-02-14 09:57:52.312 [INF] CHDB: Removing 11344 entries from edge update index.
2021-02-14 09:57:52.771 [INF] CHDB: Repopulating edge update index with 12278 valid entries.
2021-02-14 09:57:53.599 [INF] CHDB: Migration to properly prune edge update index complete!
2021-02-14 09:57:53.599 [INF] CHDB: Applying migration #7
2021-02-14 09:57:53.599 [INF] CHDB: Migrating to new closed channel format...
2021-02-14 09:57:53.600 [INF] CHDB: Migration to new closed channel format complete!
2021-02-14 09:57:53.600 [INF] CHDB: Applying migration #8
2021-02-14 09:57:53.600 [INF] CHDB: Migrating to the gossip message store new key format
2021-02-14 09:57:53.600 [INF] CHDB: Migration to the gossip message store new key format complete!
2021-02-14 09:57:53.600 [INF] CHDB: Applying migration #9
2021-02-14 09:57:53.600 [INF] CHDB: Migrating outgoing payments to new bucket structure
2021-02-14 09:57:53.600 [INF] CHDB: No outgoing payments found, nothing to migrate.
2021-02-14 09:57:53.600 [INF] CHDB: Applying migration #10
2021-02-14 09:57:53.600 [INF] CHDB: Applying migration #11
2021-02-14 09:57:53.600 [INF] CHDB: Migrating invoices to new invoice format
2021-02-14 09:57:53.601 [INF] CHDB: Migration of invoices completed!
2021-02-14 09:57:53.601 [INF] CHDB: Applying migration #12
2021-02-14 09:57:53.601 [INF] CHDB: Migrating invoice bodies to TLV, adding payment addresses and feature vectors.
2021-02-14 09:57:53.602 [INF] CHDB: Migration to TLV invoice bodies, payment address, and features complete!
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #13
2021-02-14 09:57:53.602 [INF] CHDB: Migrating payments to mpp structure
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #14
2021-02-14 09:57:53.602 [INF] CHDB: Creating top-level bucket: "pay-addr-index" ...
2021-02-14 09:57:53.602 [INF] CHDB: Created top-level bucket: "pay-addr-index"
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #15
2021-02-14 09:57:53.602 [INF] CHDB: Creating top-level bucket: "payments-index-bucket" ...
2021-02-14 09:57:53.602 [INF] CHDB: Created top-level bucket: "payments-index-bucket"
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #16
2021-02-14 09:57:53.602 [INF] CHDB: Migrating payments to add sequence number index
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #17
2021-02-14 09:57:53.602 [INF] CHDB: Creating top-level bucket: "close-summaries" ...
2021-02-14 09:57:53.602 [INF] CHDB: Created top-level bucket: "close-summaries"
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #18
2021-02-14 09:57:53.602 [INF] CHDB: Creating top-level bucket: "peers-bucket" ...
2021-02-14 09:57:53.602 [INF] CHDB: Created top-level bucket: "peers-bucket"
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #19
2021-02-14 09:57:53.602 [INF] CHDB: Creating top-level bucket: "outpoint-bucket" ...
2021-02-14 09:57:53.602 [INF] CHDB: Created top-level bucket: "outpoint-bucket"
2021-02-14 09:57:53.602 [INF] CHDB: Applying migration #20
2021-02-14 09:57:53.706 [INF] LTND: Database now open (time_to_open=2.04585985s)!
2021-02-14 09:57:53.734 [INF] RPCS: Password gRPC proxy started at 0.0.0.0:10009
2021-02-14 09:57:53.734 [INF] RPCS: Password RPC server listening on 0.0.0.0:8085
2021-02-14 09:57:53.734 [INF] LTND: Waiting for wallet encryption password. Use lncli create to create a wallet, lncli unlock to unlock an existing wallet, or lncli changepassword to change the password of an existing wallet and unlock it.
2021-02-14 09:58:26.100 [INF] LNWL: Applying wallet transaction manager migration #2
2021-02-14 09:58:26.100 [INF] LNWL: Dropping wallet transaction history
2021-02-14 09:58:26.100 [ERR] LNWL: Unable to apply wallet transaction manager migration #2: failed to delete locked outputs bucket: bucket not found

[DebugSlug]

It looks like your macaroons aren't created because lnd isn't even able to start up to the point where it would create them.
Can you try this please:

• Make sure only one instance of lnd is running (the unable to obtain database backends: timeout sounds like another process is locking the database).
• Start lnd and observe the log. It should run through some database migrations and then prompt you to unlock the wallet.

If that doesn't work then please post the log and your current configuration file.

Lnd is on autorun every time the system starts up. Went straight to log into my wallet by using lncli unlock and I got the error:

failed to delete locked outputs bucket: bucket not found

Log

`2021-02-14 17:21:25.220 [INF] CHDB: Creating top-level bucket: "outpoint-bucket" ...

2021-02-14 17:21:25.221 [INF] CHDB: Created top-level bucket: "outpoint-bucket"

2021-02-14 17:21:25.221 [INF] CHDB: Applying migration #20

2021-02-14 17:21:25.358 [INF] LTND: Database now open (time_to_open=14.177894971s)!

2021-02-14 17:21:25.491 [INF] RPCS: Password RPC server listening on 127.0.0.1:10009

2021-02-14 17:21:25.496 [INF] RPCS: Password gRPC proxy started at 127.0.0.1:8080

2021-02-14 17:21:25.496 [INF] LTND: Waiting for wallet encryption password. Use lncli create to create a wallet, lncli unlock to unlock an existing wallet, or lncli changepassword to change the password of an existing wallet and unlock it.

2021-02-14 18:13:38.318 [INF] LNWL: Applying wallet transaction manager migration #2

2021-02-14 18:13:38.318 [INF] LNWL: Dropping wallet transaction history

2021-02-14 18:13:38.357 [ERR] LNWL: Unable to apply wallet transaction manager migration #2: failed to delete locked outputs bucket: bucket not found
`

Config

`# SlugNode LND Mainnet: lnd configuration

/home/bitcoin/.lnd/lnd.conf

[Application Options]
alias=SlugNode
color=#FFFF00
debuglevel=info
maxpendingchannels=5
listen=localhost

[Bitcoin]
bitcoin.active=1
bitcoin.mainnet=1
bitcoin.node=bitcoind

[tor]
tor.active=true
tor.v3=true
tor.streamisolation=true
`

I may have tried to install the new lnd without stopping the service. Would that cause the kind of problems I'm experiencing now?

[guggero]

It looks like the wallet database migration isn't successful.
Can you try if the error goes away if you run with --reset-wallet-transactions? That's only available in 0.12.0 and later.

If that shows the same error, it's probably easiest to restore the wallet from the seed. That will cause the chain to be re-scanned and take a while but at least it should work again afterwards.
So if you still have the seed, follow these instructions:

• Shut down lnd.
• Delete the following files (nothing else!): wallet.db, macaroons.db, *.macaroon in the .lnd/data/chain/bitcoin/mainnet directory.
• Start lnd again.
• Run lncli create and use the same seed as before.
• Observe the log. It should re-scan the chain and then come online normally. The channels should be preserved, though after such a long down time it's very likely that all your peers force closed on you and they will all be in a pending close state.

[wpaulino]

[ERR] LNWL: Unable to apply wallet transaction manager migration #2: failed to delete locked outputs bucket: bucket not found

This migration error is actually a bug, I've opened btcsuite/btcwallet#731 to resolve it. Once it gets merged and the dependency is updated in lnd, the migration should succeed and allow the node to fully start up (barring any other unrelated errors).

[DebugSlug]

It looks like the wallet database migration isn't successful.
Can you try if the error goes away if you run with --reset-wallet-transactions? That's only available in 0.12.0 and later.

If that shows the same error, it's probably easiest to restore the wallet from the seed. That will cause the chain to be re-scanned and take a while but at least it should work again afterwards.
So if you still have the seed, follow these instructions:

• Shut down lnd.
• Delete the following files (nothing else!): wallet.db, macaroons.db, *.macaroon in the .lnd/data/chain/bitcoin/mainnet directory.
• Start lnd again.
• Run lncli create and use the same seed as before.
• Observe the log. It should re-scan the chain and then come online normally. The channels should be preserved, though after such a long down time it's very likely that all your peers force closed on you and they will all be in a pending close state.

No go using --reset-wallet-transactions

Removed wallet.db, macaroons.db, *.macaroon , although there were never *.macaroons there before. Tried an on chain restore using my seed, but tor setting in my lnd.conf was causing LND to shutdown before even starting up so I deleted the tor settings in lnd.conf.

After that, macaroons were finally created. I unlocked LND and now LNWL is rescanning blocks in my log. Will update again after the scanning is done.

[DebugSlug]

Seems the scan is over. Log has this output now:

2021-02-21 16:00:42.793 [INF] NTFN: New block: height=671617, sha=000000000000000000072242a343707da525db5f8f0ea1c5890a041dc0bae0bf
2021-02-21 16:00:42.917 [INF] UTXN: Attempting to graduate height=671617: num_kids=0, num_babies=0

entered lncli walletbalance and it is showing zero across the board. Should have 0.0151 in there. Did it not work or are all my funds still in a pending close state and I must wait longer?

[guggero]

What does lncli listchannels and lncli pendingchannels say? Did you have on-chain funds before or did you put everything into channels?

[DebugSlug]

What does lncli listchannels and lncli pendingchannels say? Did you have on-chain funds before or did you put everything into channels?

Ahhh, ok log is doing something different now. Didn't think it would take this long. Guess I should've been more patient. Log before checking lncli pendingchannels output:

[INF] LNWL: Inserting unconfirmed transaction f61974b9d41505aa5accc8ff6137b3a648942c493284d67ebb6c04dac60bf034
2021-02-22 19:48:22.940 [INF] LNWL: Removed invalid transaction: (*wire.MsgTx)(0x48bdde0)({

Now in lncli pendingchannels i see:

 "total_limbo_balance": "1143988",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b",
                "channel_point": "ae0a1a8e0f106c8148b126ab834c416626530233b33812bca6dc2d0d4f1a2499:1",
                "capacity": "1515153",
                "local_balance": "1143988",
                "remote_balance": "0",
                "local_chan_reserve_sat": "0",
                "remote_chan_reserve_sat": "0",
                "initiator": "INITIATOR_LOCAL",
                "commitment_type": "LEGACY"
            },
            "closing_txid": "0a11927dbda532035ab9c98b91d50c5f98f6c2235bd451121e532defd2daf98c",
            "limbo_balance": "1143988",
            "maturity_height": 533596,
            "blocks_til_maturity": -138176,
            "recovered_balance": "0",
            "pending_htlcs": [
            ],
            "anchor": "LIMBO"
        }
    ],
    "waiting_close_channels": [
    ]
}

Guess I just have to wait on the channels to close, it seems, and then I can start sorting out what channels I'd like my funds to go too. I see my original capacity in there. So looks like it'll eventually be back to normal after sometime, right?

[DebugSlug]

I'm also getting this in my log. Not sure if this is an error that needs to be fixed:

2021-02-22 21:15:00.185 [ERR] SWPR: input cluster sweep: unable to sweep inputs: publish tx: unmatched backend error: -26: non-mandatory-script-verify-flag (Signature must be zero for failed CHECK(MULTI)SIG operation)

[guggero]

I looked at the chain and the channel was closed a long time ago. Your wallet is now rescanning the chain and will find that out soon as well. It should be able to sweep the funds soon. Make sure you are connected to Rompert (the node on the other side, try lncli connect 02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b@167.99.50.31:9735).
Because it's a channel of the LEGACY format, you'll need a secret from that node to be able to sweep. Check the logs for messages from 02ad6fb... to see if you're connected to them.

[DebugSlug]

I looked at the chain and the channel was closed a long time ago. Your wallet is now rescanning the chain and will find that out soon as well. It should be able to sweep the funds soon. Make sure you are connected to Rompert (the node on the other side, try lncli connect 02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b@167.99.50.31:9735).
Because it's a channel of the LEGACY format, you'll need a secret from that node to be able to sweep. Check the logs for messages from 02ad6fb... to see if you're connected to them.

Did what you instructed. Conncected to Rompert now. I was getting direct gossipsync here:

2021-02-23 21:24:51.336 [INF] DISC: GossipSyncer(02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)

LN still says in still connected to Rompert, although it is GossipSyncing to a different address now:

2021-02-24 00:24:51.336 [INF] DISC: GossipSyncer(03fc644fbb6d0cdf17496f9d6c480f084e980606ada3f7d0de2e32138f5f580d6b): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2021-02-24 00:24:51.337 [INF] DISC: GossipSyncer(037f990e61acee8a7697966afd29dd88f3b1f8a7b14d625c4f8742bd952003a590): applying gossipFilter(start=2021-02-24 00:24:51.337111797 -0600 CST m=+278787.375598939, end=2157-04-02 07:53:06.337111797 -0500 `CDT)`

I'll let it run overnight. Will be back after work tomorrow.

[DebugSlug]

Wanted to give it some time so I waited an extra day. Still getting the same error over and over even after connecting to Rompert.

2021-02-25 20:13:51.550 [INF] SWPR: Creating sweep transaction 91da4a5a99731d12b91dd54feeaf4dd8645195f6be0733470b00d76c64c0d8eb for 1 inputs (0a11927dbda532035ab9c98b91d50c5f98f6c2235bd451121e532defd2daf98c:0 (CommitmentNoDelay)) using 35715 sat/kw, tx_weight=439, tx_fee=0.00015678 BTC, parents_count=0, parents_fee=0 BTC, parents_weight=0
2021-02-25 20:13:51.605 [INF] LNWL: Inserting unconfirmed transaction 91da4a5a99731d12b91dd54feeaf4dd8645195f6be0733470b00d76c64c0d8eb
2021-02-25 20:13:51.708 [INF] LNWL: Removed invalid transaction: (*wire.MsgTx)(0x616b060)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=15) {
  (*wire.TxIn)(0x32170c0)({
   PreviousOutPoint: (wire.OutPoint) 0a11927dbda532035ab9c98b91d50c5f98f6c2235bd451121e532defd2daf98c:0,
   SignatureScript: ([]uint8) <nil>,
   Witness: (wire.TxWitness) (len=2 cap=2) {
    ([]uint8) (len=72 cap=144) {
     00000000  30 45 02 21 00 db 48 fe  54 bd cc 48 15 08 9e 33  |0E.!..H.T..H...3|
     00000010  4b 9f c6 14 5e f0 f8 c1  c9 a3 28 82 65 34 3b 15  |K...^.....(.e4;.|
     00000020  d8 53 f1 08 3e 02 20 72  04 a5 7e c1 e1 79 0b 0a  |.S..>. r..~..y..|
     00000030  ac 87 ef 3b 20 71 0b 5d  ea f2 86 8d e5 5f bb ef  |...; q.]....._..|
     00000040  a8 df f7 4a 17 b4 b6 01                           |...J....|
    },
    ([]uint8) (len=33 cap=33) {
     00000000  03 de 11 33 51 c1 6a 90  c8 8e 31 97 6f e4 ff c5  |...3Q.j...1.o...|
     00000010  c2 19 77 93 b6 11 ba f4  6b d2 fb ec 84 79 28 df  |..w.....k....y(.|
     00000020  a9                                                |.|
    }
   },
   Sequence: (uint32) 0
  })
 },
 TxOut: ([]*wire.TxOut) (len=1 cap=15) {
  (*wire.TxOut)(0x616b080)({
   Value: (int64) 1128310,
   PkScript: ([]uint8) (len=22 cap=500) {
    00000000  00 14 34 ee 00 f6 cd 1e  d7 95 57 93 95 54 fc 67  |..4.......W..T.g|
    00000010  2b 0d ac 83 0e 19                                 |+.....|
   }
  })
 },
 LockTime: (uint32) 672208
})

2021-02-25 20:13:51.708 [ERR] SWPR: input cluster sweep: unable to sweep inputs: publish tx: unmatched backend error: -26: non-mandatory-script-verify-flag (Signature must be zero for failed CHECK(MULTI)SIG operation)

Not sure if I should just wait longer? No matter the size of the transaction when the sweep happens, the result is (Signature must be zero for failed CHECK(MULTI)SIG operation) at the end of the above operation.

Not sure what, or if, I should do more but just hang out and wait.

[wpaulino]

Seems similar to #4888? cc @guggero