Lnd: SRVR: unable to start server: edge not found

[corbelantoine]

Background

Issue is somewhat similar to what is there:
https://github.com/lightningnetwork/lnd/issues/1938

I upgraded my node to the last version of LND. The node had been shutdown for about a month and caught up using the new version. It worked fine for about 12 hours, I could even send 2 payments, after that it just crashed (logs stopped for 1min and the node restarted after that).

...
2019-04-28 19:44:15.147 [DBG] CNCT: ChannelArbitrator(dd86576ac02a0a361d2e9086bb23cf8d139fccfd2bd82fb76f1cd947d4da5c0a:0): new block (height=573650) examining active HTLC's
2019-04-28 19:44:15.149 [DBG] CNCT: ChannelArbitrator(dd86576ac02a0a361d2e9086bb23cf8d139fccfd2bd82fb76f1cd947d4da5c0a:0): checking chain actions at height=573650
2019-04-28 19:44:15.156 [DBG] CNCT: ChannelArbitrator(2c056f7d16ba3802b348b8d2904d70ca8f4318bab3d50fa6dc2f3ac2f82ba3e1:0): new block (height=573650) examining active HTLC's
2019-04-28 19:44:15.156 [DBG] CNCT: ChannelArbitrator(2c056f7d16ba3802b348b8d2904d70ca8f4318bab3d50fa6dc2f3ac2f82ba3e1:0): checking chain actions at height=573650
2019-04-28 19:44:15.156 [DBG] CNCT: Starting ChannelArbitrator(5beab5e5b7d36e9eaff3d574f733460d89d147e1bed1bb1388740b02ffe539e5:0), htlc_set=(contractcourt.htlcSet) {
 incomingHTLCs: (map[uint64]channeldb.HTLC) {
 },
 outgoingHTLCs: (map[uint64]channeldb.HTLC) {
 }
}

2019-04-28 19:44:15.156 [INF] CNCT: ChannelArbitrator(5beab5e5b7d36e9eaff3d574f733460d89d147e1bed1bb1388740b02ffe539e5:0): starting state=StateDefault
2019-04-28 19:44:15.156 [DBG] CNCT: ChannelArbitrator(2c056f7d16ba3802b348b8d2904d70ca8f4318bab3d50fa6dc2f3ac2f82ba3e1:0): new block (height=573650) examining active HTLC's
2019-04-28 19:44:15.157 [DBG] CNCT: ChannelArbitrator(2c056f7d16ba3802b348b8d2904d70ca8f4318bab3d50fa6dc2f3ac2f82ba3e1:0): checking chain actions at height=573650
2019-04-28 19:44:15.164 [DBG] CNCT: ChannelArbitrator(5beab5e5b7d36e9eaff3d574f733460d89d147e1bed1bb1388740b02ffe539e5:0): new block (height=573650) examining active HTLC's
2019-04-28 19:44:15.164 [DBG] CNCT: ChannelArbitrator(5beab5e5b7d36e9eaff3d574f733460d89d147e1bed1bb1388740b02ffe539e5:0): checking chain actions at height=573650
2019-04-28 19:44:15.164 [DBG] CNCT: ChannelArbitrator(5beab5e5b7d36e9eaff3d574f733460d89d147e1bed1bb1388740b02ffe539e5:0): new block (height=573650) examining active HTLC's
2019-04-28 19:44:15.167 [DBG] CNCT: ChannelArbitrator(5beab5e5b7d36e9eaff3d574f733460d89d147e1bed1bb1388740b02ffe539e5:0): checking chain actions at height=573650
2019-04-28 19:44:15.259 [INF] DISC: Authenticated Gossiper is starting
2019-04-28 19:44:15.259 [INF] BRAR: Starting contract observer, watching for breaches.
2019-04-28 19:44:15.259 [INF] NTFN: New block epoch subscription
2019-04-28 19:44:15.266 [INF] CRTR: FilteredChainView starting
2019-04-28 19:44:19.566 [ERR] SRVR: unable to start server: edge not found

2019-04-28 19:44:19.566 [INF] RPCS: Stopping RPC Server
2019-04-28 19:44:19.571 [INF] LTND: Shutdown complete

Your environment

LND v0.6
bitcoind v0.17.1
Raspbian 9.4
I'm using a Raspberry, everything is stored on a hard drive

[fluidvoice]

I'm seeing this "edge not found" error also on RaspiBlitz (Raspberry Pi) with v0.6-beta
https://github.com/rootzoll/raspiblitz/issues/562#issue-439226880
RaspiBlitz debug log: https://termbin.com/ya0h
Note: initially it was working then stopped:

[fluidvoice]

restarted with debuglevel=debug logs here: https://termbin.com/h7ia

2019-05-01 18:26:39.900 [INF] LTND: Version: 0.6.0-beta commit=v0.6-beta, build=production, logging=default
2019-05-01 18:26:39.901 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2019-05-01 18:26:40.006 [INF] CHDB: Checking for schema update: latest_version=8, db_version=8
2019-05-01 18:26:40.046 [INF] RPCS: password RPC server listening on [::]:10009
2019-05-01 18:26:40.053 [INF] RPCS: password gRPC proxy started at [::]:8080
2019-05-01 18:26:40.053 [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.
2019-05-01 20:05:55.127 [INF] LNWL: Opened wallet
2019-05-01 20:05:55.649 [INF] LTND: Primary chain is set to: bitcoin
2019-05-01 20:05:55.861 [INF] LTND: Initializing bitcoind backed fee estimator
2019-05-01 20:05:55.856 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on tcp://:28332
2019-05-01 20:05:55.857 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on tcp://:28333
2019-05-01 20:05:55.911 [DBG] LNWL: Using minimum fee rate of 253 sat/kw
2019-05-01 20:06:02.065 [INF] LNWL: The wallet has been unlocked without a time limit
2019-05-01 20:06:02.087 [DBG] LNWL: Birthday block has already been verified: height=553299, hash=0000000000000000002fb5012be16342623a11878216e6b9fc2b75cf4f702ece
2019-05-01 20:06:02.087 [INF] LTND: LightningWallet opened
2019-05-01 20:06:02.115 [INF] SRVR: Proxying all network traffic via Tor (stream_isolation=false)! NOTE: Ensure the backend node is proxying over Tor as well
2019-05-01 20:06:02.177 [INF] HSWC: Restoring in-memory circuit state from disk
2019-05-01 20:06:02.181 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0
2019-05-01 20:06:02.310 [INF] LTND: Channel backup proxy channel notifier starting
2019-05-01 20:06:02.313 [INF] ATPL: Instantiating autopilot with cfg: (*main.autoPilotConfig)(0x289c720)({
Active: (bool) false,
Heuristic: (map[string]float64) (len=1) {
(string) (len=12) "preferential": (float64) 1
},
MaxChannels: (int) 5,
Allocation: (float64) 0.6,
MinChannelSize: (int64) 20000,
MaxChannelSize: (int64) 16777215,
Private: (bool) false,
MinConfs: (int32) 0
})

2019-05-01 20:06:02.313 [DBG] LTND: Populating dependencies for sub RPC server: SignRPC
2019-05-01 20:06:02.314 [DBG] LTND: Populating dependencies for sub RPC server: WalletKitRPC
2019-05-01 20:06:02.325 [DBG] LTND: Populating dependencies for sub RPC server: AutopilotRPC
2019-05-01 20:06:02.325 [DBG] LTND: Populating dependencies for sub RPC server: ChainRPC
2019-05-01 20:06:02.325 [DBG] LTND: Populating dependencies for sub RPC server: InvoicesRPC
2019-05-01 20:06:02.325 [DBG] LTND: Populating dependencies for sub RPC server: RouterRPC
2019-05-01 20:06:02.331 [DBG] SGNR: Signer RPC server successfully register with root gRPC server
2019-05-01 20:06:02.331 [DBG] IRPC: Invoices RPC server successfully registered with root gRPC server
2019-05-01 20:06:02.331 [DBG] WLKT: WalletKit RPC server successfully registered with root gRPC server
2019-05-01 20:06:02.332 [DBG] RPCS: Starting sub RPC server: SignRPC
2019-05-01 20:06:02.332 [DBG] RPCS: Starting sub RPC server: ChainRPC
2019-05-01 20:06:02.332 [DBG] RPCS: Starting sub RPC server: InvoicesRPC
2019-05-01 20:06:02.332 [DBG] RPCS: Starting sub RPC server: WalletKitRPC
2019-05-01 20:06:02.336 [INF] RPCS: RPC server listening on [::]:10009
2019-05-01 20:06:02.348 [INF] RPCS: gRPC proxy started at [::]:8080
2019-05-01 20:06:02.352 [INF] LTND: Waiting for chain backend to finish sync, start_height=574136
2019-05-01 20:06:02.570 [INF] LNWL: Started rescan from block 000000000000000000140d82ddcf0213efd721e13c559e3f3c8b6541ee5b9b40 (height 574118) for 140 addresses
2019-05-01 20:06:02.582 [INF] LNWL: Starting rescan from block 000000000000000000140d82ddcf0213efd721e13c559e3f3c8b6541ee5b9b40
2019-05-01 20:06:03.532 [DBG] LNWL: Filtering block 574119 (00000000000000000012c6878e23191368494513516f3c74a2909bf2a11a6fa4) with 2991 transactions
2019-05-01 20:06:05.605 [DBG] LNWL: Filtering block 574120 (00000000000000000003454560c6d3fc7ea26db54ba809c234306558c81cf327) with 3350 transactions
2019-05-01 20:06:07.677 [DBG] LNWL: Filtering block 574121 (00000000000000000019ffaccb71cff51bd795e25afa96048e44cec6fa51c6d0) with 3116 transactions
2019-05-01 20:06:10.034 [DBG] LNWL: Filtering block 574122 (0000000000000000000ab123371796b47ce9942eb9c89a0a720b31ce432e265b) with 3135 transactions
2019-05-01 20:06:12.329 [DBG] LNWL: Filtering block 574123 (0000000000000000001fcf43fe35e850f845e83053bb865bf1a6938c813ab603) with 3359 transactions
2019-05-01 20:06:14.271 [DBG] LNWL: Filtering block 574124 (0000000000000000000d3d1ddb4fe04ca73cdccefceb3dea6ef4a7450dfaaebf) with 3058 transactions
2019-05-01 20:06:16.295 [DBG] LNWL: Filtering block 574125 (0000000000000000000a32c582618e2606c99d57fafe70b92dd6ed34178625cf) with 3242 transactions
2019-05-01 20:06:18.338 [DBG] LNWL: Filtering block 574126 (000000000000000000076a286401e3b0044c68001982fd29b3a751706f5e49f8) with 3209 transactions
2019-05-01 20:06:20.513 [DBG] LNWL: Filtering block 574127 (00000000000000000018fd3a9803c10f1feda2eada863192d5b06eff94510c09) with 2909 transactions
2019-05-01 20:06:22.580 [DBG] LNWL: Filtering block 574128 (0000000000000000000d7b1179e9fac88a2975d4a4bb7d6dfe33e54b848bd882) with 2901 transactions
2019-05-01 20:06:24.688 [DBG] LNWL: Filtering block 574129 (00000000000000000009269c77679215b324810d4f6868ddd1b7a4e0daf814aa) with 1979 transactions
2019-05-01 20:06:26.616 [DBG] LNWL: Filtering block 574130 (0000000000000000000d2768529e41f1ca6154eb0d356852f1b9d97ef1b9a7b4) with 3008 transactions
2019-05-01 20:06:28.802 [DBG] LNWL: Filtering block 574131 (0000000000000000001b9bd6a26aa31b7801fcb959b45cca8b10c887a9344106) with 3203 transactions
2019-05-01 20:06:30.733 [DBG] LNWL: Filtering block 574132 (00000000000000000024201b7f0159cc8ef623ecf4c0aa528f308c3aaa4524e2) with 3175 transactions
2019-05-01 20:06:32.928 [DBG] LNWL: Filtering block 574133 (0000000000000000002504c6708ba10e8ba82b812218bf0debb77923b3eb404d) with 3358 transactions
2019-05-01 20:06:35.102 [DBG] LNWL: Filtering block 574134 (00000000000000000005c85248b3d9d6b875e40875066a43343c86979089d840) with 3079 transactions
2019-05-01 20:06:37.210 [DBG] LNWL: Filtering block 574135 (0000000000000000002b859ec1a518d3bb6ff643d9df23492242a7c23fafec5c) with 3031 transactions
2019-05-01 20:06:39.310 [DBG] LNWL: Filtering block 574136 (0000000000000000000ee46e8e399c887c8e1405276190e59025cfd0fd7605d6) with 3343 transactions
2019-05-01 20:06:40.390 [INF] LNWL: Rescan finished at 574118 (000000000000000000140d82ddcf0213efd721e13c559e3f3c8b6541ee5b9b40)
2019-05-01 20:06:40.390 [INF] LNWL: Catching up block hashes to height 574118, this might take a while
2019-05-01 20:06:40.391 [INF] LNWL: Done catching up block hashes
2019-05-01 20:06:40.391 [INF] LNWL: Finished rescan for 140 addresses (synced to block 000000000000000000140d82ddcf0213efd721e13c559e3f3c8b6541ee5b9b40, height 574118)
2019-05-01 20:06:40.990 [INF] LTND: Chain backend is fully synced (end_height=574136)!
2019-05-01 20:06:41.095 [INF] HSWC: Starting HTLC Switch
2019-05-01 20:06:41.095 [INF] NTFN: New block epoch subscription
2019-05-01 20:06:41.095 [INF] NTFN: New block epoch subscription
2019-05-01 20:06:41.099 [DBG] SWPR: Best height: 574136
2019-05-01 20:06:41.099 [INF] NTFN: New block epoch subscription
2019-05-01 20:06:41.165 [INF] NTFN: New block epoch subscription
2019-05-01 20:06:41.250 [INF] DISC: Authenticated Gossiper is starting
2019-05-01 20:06:41.250 [INF] BRAR: Starting contract observer, watching for breaches.
2019-05-01 20:06:41.250 [INF] NTFN: New block epoch subscription
2019-05-01 20:06:41.259 [INF] CRTR: FilteredChainView starting
2019-05-01 20:06:46.172 [ERR] SRVR: unable to start server: edge not found

2019-05-01 20:06:46.172 [INF] RPCS: Stopping RPC Server
2019-05-01 20:06:46.173 [INF] RPCS: Stopping SignRPC Sub-RPC Server
2019-05-01 20:06:46.173 [INF] RPCS: Stopping ChainRPC Sub-RPC Server
2019-05-01 20:06:46.173 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server
2019-05-01 20:06:46.173 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server
2019-05-01 20:06:46.174 [INF] LTND: Shutdown complete

[halseth]

@fluidvoice Thanks for reporting! Can you try reproducing with this patch?

diff --git a/channeldb/graph.go b/channeldb/graph.go
index eaf3503c..9edd2955 100644
--- a/channeldb/graph.go
+++ b/channeldb/graph.go
@@ -3025,7 +3025,8 @@ func (c *ChannelGraph) ChannelView() ([]EdgePoint, error) {
                edgeIndex, chanID,
            )
            if err != nil {
-               return err
+               return fmt.Errorf("failed fetching edge info "+
+                   "for chanpoint %v: %v", chanPoint, err)
            }

            pkScript, err := genMultiSigP2WSH(
@@ -3456,7 +3457,8 @@ func fetchChanEdgeInfo(edgeIndex *bbolt.Bucket,

    edgeInfoBytes := edgeIndex.Get(chanID)
    if edgeInfoBytes == nil {
-       return ChannelEdgeInfo{}, ErrEdgeNotFound
+       return ChannelEdgeInfo{}, fmt.Errorf("chanID %x not found in "+
+           "edgeindex", chanID[:])
    }

    edgeInfoReader := bytes.NewReader(edgeInfoBytes)

[halseth]

also @corbelantoine

[fluidvoice]

Can you try reproducing with this patch?

OK, will giver a try. Also I want to test by backing out TOR. Because initially when I first upgraded to v1.2 of Raspiblitz it was working without TOR. Then I made some changes, one of which was turning on TOR and that was when it got into this failure state.

[fluidvoice]

Turned off TOR but problem persists: https://termbin.com/ol2z

[INF] LTND: Version: 0.6.0-beta commit=v0.6-beta, build=production, logging=default
2019-05-03 19:09:59.449 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2019-05-03 19:09:59.476 [INF] CHDB: Checking for schema update: latest_version=8, db_version=8
2019-05-03 19:09:59.496 [INF] RPCS: password RPC server listening on [::]:10009
2019-05-03 19:09:59.500 [INF] RPCS: password gRPC proxy started at [::]:8080
2019-05-03 19:09:59.500 [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.
2019-05-03 19:10:34.231 [INF] LNWL: Opened wallet
2019-05-03 19:10:34.708 [INF] LTND: Primary chain is set to: bitcoin
2019-05-03 19:10:34.772 [INF] LTND: Initializing bitcoind backed fee estimator
2019-05-03 19:10:34.772 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on tcp://:28333
2019-05-03 19:10:34.773 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on tcp://:28332
2019-05-03 19:10:34.839 [DBG] LNWL: Using minimum fee rate of 253 sat/kw
2019-05-03 19:10:40.977 [INF] LNWL: The wallet has been unlocked without a time limit
2019-05-03 19:10:40.985 [INF] LTND: LightningWallet opened
2019-05-03 19:10:40.986 [DBG] LNWL: Birthday block has already been verified: height=553299, hash=0000000000000000002fb5012be16342623a11878216e6b9fc2b75cf4f702ece
2019-05-03 19:10:41.023 [INF] HSWC: Restoring in-memory circuit state from disk
2019-05-03 19:10:41.034 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0
2019-05-03 19:10:41.121 [INF] LTND: Channel backup proxy channel notifier starting
2019-05-03 19:10:41.122 [INF] ATPL: Instantiating autopilot with cfg: (*main.autoPilotConfig)(0x204c6c0)({
Active: (bool) false,
Heuristic: (map[string]float64) (len=1) {
(string) (len=12) "preferential": (float64) 1
},
MaxChannels: (int) 5,
Allocation: (float64) 0.6,
MinChannelSize: (int64) 20000,
MaxChannelSize: (int64) 16777215,
Private: (bool) false,
MinConfs: (int32) 0
})

2019-05-03 19:10:41.123 [DBG] LTND: Populating dependencies for sub RPC server: SignRPC
2019-05-03 19:10:41.123 [DBG] LTND: Populating dependencies for sub RPC server: WalletKitRPC
2019-05-03 19:10:41.124 [DBG] LTND: Populating dependencies for sub RPC server: AutopilotRPC
2019-05-03 19:10:41.124 [DBG] LTND: Populating dependencies for sub RPC server: ChainRPC
2019-05-03 19:10:41.124 [DBG] LTND: Populating dependencies for sub RPC server: InvoicesRPC
2019-05-03 19:10:41.124 [DBG] LTND: Populating dependencies for sub RPC server: RouterRPC
2019-05-03 19:10:41.144 [DBG] SGNR: Signer RPC server successfully register with root gRPC server
2019-05-03 19:10:41.145 [DBG] IRPC: Invoices RPC server successfully registered with root gRPC server
2019-05-03 19:10:41.145 [DBG] WLKT: WalletKit RPC server successfully registered with root gRPC server
2019-05-03 19:10:41.145 [DBG] RPCS: Starting sub RPC server: SignRPC
2019-05-03 19:10:41.145 [DBG] RPCS: Starting sub RPC server: ChainRPC
2019-05-03 19:10:41.146 [DBG] RPCS: Starting sub RPC server: InvoicesRPC
2019-05-03 19:10:41.146 [DBG] RPCS: Starting sub RPC server: WalletKitRPC
2019-05-03 19:10:41.146 [INF] RPCS: RPC server listening on [::]:10009
2019-05-03 19:10:41.149 [INF] RPCS: gRPC proxy started at [::]:8080
2019-05-03 19:10:41.153 [INF] LTND: Waiting for chain backend to finish sync, start_height=574459
2019-05-03 19:10:41.390 [INF] LNWL: Started rescan from block 0000000000000000000eeddc67054024a993fa6334a7cc36e8ef93f79417a6d5 (height 574459) for 140 addresses
2019-05-03 19:10:41.396 [INF] LNWL: Starting rescan from block 0000000000000000000eeddc67054024a993fa6334a7cc36e8ef93f79417a6d5
2019-05-03 19:10:41.406 [INF] LNWL: Rescan finished at 574459 (0000000000000000000eeddc67054024a993fa6334a7cc36e8ef93f79417a6d5)
2019-05-03 19:10:41.406 [INF] LNWL: Catching up block hashes to height 574459, this might take a while
2019-05-03 19:10:41.408 [INF] LNWL: Done catching up block hashes
2019-05-03 19:10:41.408 [INF] LNWL: Finished rescan for 140 addresses (synced to block 0000000000000000000eeddc67054024a993fa6334a7cc36e8ef93f79417a6d5, height 574459)
2019-05-03 19:10:42.408 [INF] LTND: Chain backend is fully synced (end_height=574459)!
2019-05-03 19:10:42.439 [INF] HSWC: Starting HTLC Switch
2019-05-03 19:10:42.439 [INF] NTFN: New block epoch subscription
2019-05-03 19:10:42.440 [INF] NTFN: New block epoch subscription
2019-05-03 19:10:42.446 [DBG] SWPR: Best height: 574459
2019-05-03 19:10:42.446 [INF] NTFN: New block epoch subscription
2019-05-03 19:10:42.564 [INF] NTFN: New block epoch subscription
2019-05-03 19:10:42.667 [INF] DISC: Authenticated Gossiper is starting
2019-05-03 19:10:42.667 [INF] BRAR: Starting contract observer, watching for breaches.
2019-05-03 19:10:42.667 [INF] NTFN: New block epoch subscription
2019-05-03 19:10:42.678 [INF] CRTR: FilteredChainView starting
2019-05-03 19:10:48.601 [ERR] SRVR: unable to start server: edge not found

2019-05-03 19:10:48.601 [INF] RPCS: Stopping RPC Server
2019-05-03 19:10:48.601 [INF] RPCS: Stopping SignRPC Sub-RPC Server
2019-05-03 19:10:48.601 [INF] RPCS: Stopping ChainRPC Sub-RPC Server
2019-05-03 19:10:48.602 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server
2019-05-03 19:10:48.602 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server
2019-05-03 19:10:48.604 [INF] LTND: Shutdown complete

[fluidvoice]

We have another Pi user reporting the same problem on Raspiblitz v1.2: https://github.com/rootzoll/raspiblitz/issues/575#issuecomment-489427743

[halseth]

@fluidvoice TOR should have nothing to do with this error, it looks like the database state is non-consistent.

[fluidvoice]

@fluidvoice TOR should have nothing to do with this error, it looks like the database state is non-consistent.

good to know, thanks.

[fluidvoice]

trying to build latest rc1 to test n see if it reproduces with the latest: https://github.com/lightningnetwork/lnd/issues/3040#issuecomment-489659737
building based on the release notes direction, my build fails with output: https://termbin.com/ytqr

[fluidvoice]

@fluidvoice Thanks for reporting! Can you try reproducing with this patch?

can't apply the patch as I'm not able to build lnd per post above this one.

[wpaulino]

@fluidvoice is this with go 1.12?

[fluidvoice]

@fluidvoice is this with go 1.12?

yes, why?

admin@thunda:~/raspiblitz/lnd/build/git/lnd $ go version
go version go1.12.3 linux/arm

Here I tried again with go1.12.4 but it still fails:
Complete build output is here: https://termbin.com/5s0y

[wpaulino]

From looking at the build output, it seems like your go installation is broken. I'd remove all go related files and install it from scratch again.

[fluidvoice]

From looking at the build output, it seems like your go installation is broken. I'd remove all go related files and install it from scratch again.

I'm not a go programmer. Please provide commands. Thanks.

[wpaulino]

I'm not able to provide exact commands as I'm not aware of how you set things up, so you should follow the official go documentation on how to do so.

Uninstall: https://golang.org/doc/install#uninstall
Install: https://golang.org/doc/install#install

For what it's worth, I don't think recompiling with the patch above will do much for you. From looking at https://github.com/lightningnetwork/lnd/issues/3040, it seems like you've encountered database corruption.

[fluidvoice]

For what it's worth, I don't think recompiling with the patch above will do much for you. From looking at #3040, it seems like you've encountered database corruption.

Thanks for the feedback #3040 is a different user's issue so I'll pass it on. I was just thinking maybe trying the latest would verify his problem.
My node has this "edge not found" error.

[fluidvoice]

I'm not able to provide exact commands as I'm not aware of how you set things up, so you should follow the official go documentation on how to do so.

Uninstall: https://golang.org/doc/install#uninstall
Install: https://golang.org/doc/install#install

I see Raspiblitz is installing go 1.11 onto the Pi's SD card (so will try reinstall go and reboot my Pi.):
https://github.com/rootzoll/raspiblitz/blob/480a67729081cdd81357f508c0174b9ce05fa38e/build_sdcard.sh#L546

Go is needed for ZAP connect later

echo "* Installing Go *"
wget https://storage.googleapis.com/golang/go1.11.linux-armv6l.tar.gz
if [ ! -f "./go1.11.linux-armv6l.tar.gz" ]
then
echo "!!! FAIL !!! Download not success."
exit 1
fi
sudo tar -C /usr/local -xzf go1.11.linux-armv6l.tar.gz
sudo rm *.gz
sudo mkdir /usr/local/gocode
sudo chmod 777 /usr/local/gocode
export GOROOT=/usr/local/go
export PATH=$PATH:$GOROOT/bin
export GOPATH=/usr/local/gocode
export PATH=$PATH:$GOPATH/bin
echo ""

[fluidvoice]

I'm not able to provide exact commands as I'm not aware of how you set things up, so you should follow the official go documentation on how to do so.

Uninstall: https://golang.org/doc/install#uninstall
Install: https://golang.org/doc/install#install

For what it's worth, I don't think recompiling with the patch above will do much for you. From looking at #3040, it seems like you've encountered database corruption.

OK. Looks like it built now after remove go and reinstall go1.12.4

Question: should I be building with this line per the Release notes or just with make && make install ?
GO111MODULE=on go install -v -mod=vendor -ldflags "-X github.com/lightningnetwork/lnd/build.Commit=v0.6.1-beta" ./cmd/lnd
or, should I be running this...
LNDBUILDSYS="linux-armv7" ./release.sh

[wpaulino]

You can just use make && make install if you're OK with fetching the dependencies. The release builds already provide them in the vendor directory, so there's no need to fetch them in that case.

[fluidvoice]

You can just use make && make install if you're OK with fetching the dependencies. The release builds already provide them in the vendor directory, so there's no need to fetch them in that case.

OK. Thanks for you help. I've got lnd and lncli built now. Rebooting to test things.
oh, and how do I apply that patch mentioned above?

[wpaulino]

Copy the diff into a file named patch.txt and run git apply patch.txt. Recompile, run lnd, and post the new error output.

[fluidvoice]

Copy the diff into a file named patch.txt and run git apply patch.txt. Recompile, run lnd, and post the new error output.

admin@thunda:~ $ lnd --version
lnd version 0.6.1-beta commit=v0.6.1-beta-rc1
well rc1 shows same "edge not found" error so now need to appy the patch.

2019-05-07 00:34:30.279 [DBG] LNWL: Filtering block 574911 (00000000000000000012ae3da8cb9c610acf3a648b5af5a7471b62ebb8e30902) with 3100 transactions
2019-05-07 00:34:31.686 [INF] LNWL: Rescan finished at 574608 (00000000000000000016516a94fa86ce8030ea19feec2a605ae075e118b69495)
2019-05-07 00:34:31.693 [INF] LNWL: Catching up block hashes to height 574608, this might take a while
2019-05-07 00:34:31.694 [INF] LNWL: Done catching up block hashes
2019-05-07 00:34:31.706 [INF] LNWL: Finished rescan for 140 addresses (synced to block 00000000000000000016516a94fa86ce8030ea19feec2a605ae075e118b69495, height 574608)
2019-05-07 00:34:31.943 [INF] LTND: Chain backend is fully synced (end_height=574911)!
2019-05-07 00:34:32.061 [INF] NTFN: New block epoch subscription
2019-05-07 00:34:32.070 [INF] HSWC: Starting HTLC Switch
2019-05-07 00:34:32.071 [INF] NTFN: New block epoch subscription
2019-05-07 00:34:32.079 [DBG] SWPR: Best height: 574911
2019-05-07 00:34:32.080 [INF] NTFN: New block epoch subscription
2019-05-07 00:34:32.190 [INF] NTFN: New block epoch subscription
2019-05-07 00:34:32.297 [INF] BRAR: Starting contract observer, watching for breaches.
2019-05-07 00:34:32.304 [INF] DISC: Authenticated Gossiper is starting
2019-05-07 00:34:32.345 [INF] NTFN: New block epoch subscription
2019-05-07 00:34:32.411 [INF] CRTR: FilteredChainView starting
2019-05-07 00:34:37.684 [ERR] SRVR: unable to start server: edge not found

2019-05-07 00:34:37.686 [INF] RPCS: Stopping RPC Server
2019-05-07 00:34:37.697 [INF] LTND: Shutdown complete

[fluidvoice]

Copy the diff into a file named patch.txt and run git apply patch.txt. Recompile, run lnd, and post the new error output.

@halseth @wpaulino Here is the full log file with the applied patch: https://termbin.com/bmxb

2019-05-07 01:25:23.324 [ERR] SRVR: unable to start server: failed fetching edge info for chanpoint ed29da82fca43b0fffbf81fba5d93320854e926a8fa7e688d11a2df425a95127:0: chanID 0898f10004740000 not found in edgeindex

[halseth]

@fluidvoice Thanks for running with the patch!

It does verify that the chanIndex gets out of sync with the edgeIndex. An entry that is expected to be found in the edgeIndex isn't there.

I looked through the relevant parts of the code that alters these indexes:
https://github.com/lightningnetwork/lnd/blob/c4415f04008c70be20b42f85e1ceff3ef99614c2/channeldb/graph.go#L1790
https://github.com/lightningnetwork/lnd/blob/c4415f04008c70be20b42f85e1ceff3ef99614c2/channeldb/graph.go#L592

I cannot see how these could get out of sync, so it looks like your db is corrupted indeed (happens a lot on Raspberry Pi) :/

I would try to run the bbolt tool:

go get -v -u github.com/etcd-io/bbolt/cmd/bbolt
bbolt verify <path to channel.db>

and

bbolt compact <new-temp-db> <path to channel.db>

If you can verify the new db, you can try starting lnd using it.

[fluidvoice]

it looks like your db is corrupted indeed (happens a lot on Raspberry Pi) :/

Thanks for the info. Will try.
[edit:] I was just remembering this problem started after I had enabled TOR (then later disabled it to see if it resolved the problem, which it did not). So I'm wondering if that could be a factor? Even though I disabled it in the Raspiblitz menu, I see entries in the bitcoind log that indicates it might actually still be running.
If I rename the *lnd/data dir and restart keeping all else the same, will it recreate my LND DB?*

Yes, I see LOTS of file corruption often caused by weak power supply. What I find interesting is that 90%+ of the failures occur with the LND data and much less often to the bitcoin blockchain DB. This begs the question if LND can be made more robust somehow. LND uses the same or different backend DB than bitcoind? thoughts? Or maybe it's just a result of statistics?... ie, LND is performing more I/O, more often, than bitcoind once it's synced?
I will also try to startup LND on my Linux x86 notebook using this same external HDD to verify if the DB is corrupted and/or see if the problem is specific to Pi/Arm.

[fluidvoice]

@halseth FYI just tried rc2 with same results
$ lnd --version
lnd version 0.6.1-beta commit=v0.6.1-beta-rc2

If the chain syncs and the wallet is available (not corrupted) as per this log, why can't LND recover from this "edge not found" situation?

2019-05-07 14:24:17.288 [DBG] LNWL: Filtering block 574992 (0000000000000000000516b7670d6d5d9c5a934698d67963ddce8b848b31ac40) with 2223 transactions
2019-05-07 14:24:19.573 [DBG] LNWL: Filtering block 574993 (000000000000000000158255cb5c14ffb8015d1cf548059b6ba4288f8eab4969) with 939 transactions
2019-05-07 14:24:26.264 [INF] LNWL: Rescan finished at 574915 (0000000000000000000222cbc683b8d759a179843ccbc50ddfe43d744813295c)
2019-05-07 14:24:26.282 [INF] LNWL: Catching up block hashes to height 574915, this might take a while
2019-05-07 14:24:26.308 [INF] LNWL: Done catching up block hashes
2019-05-07 14:24:26.311 [INF] LNWL: Finished rescan for 140 addresses (synced to block 0000000000000000000222cbc683b8d759a179843ccbc50ddfe43d744813295c, height 574915)
2019-05-07 14:24:32.217 [INF] LTND: Chain backend is fully synced (end_height=574993)!
2019-05-07 14:24:34.268 [INF] NTFN: New block epoch subscription
2019-05-07 14:24:34.277 [INF] HSWC: Starting HTLC Switch
2019-05-07 14:24:34.278 [INF] NTFN: New block epoch subscription
2019-05-07 14:24:34.512 [DBG] SWPR: Best height: 574993
2019-05-07 14:24:34.513 [INF] NTFN: New block epoch subscription
2019-05-07 14:24:36.979 [INF] NTFN: New block epoch subscription
2019-05-07 14:24:37.065 [INF] BRAR: Starting contract observer, watching for breaches.
2019-05-07 14:24:37.071 [INF] DISC: Authenticated Gossiper is starting
2019-05-07 14:24:37.494 [INF] NTFN: New block epoch subscription
2019-05-07 14:24:38.179 [INF] CRTR: FilteredChainView starting
2019-05-07 14:24:38.530 [DBG] RPCS: [listchannels] fetched 0 channels from DB
2019-05-07 14:24:40.674 [DBG] RPCS: [walletbalance] Total balance=0.00525315 BTC
2019-05-07 14:24:41.060 [DBG] RPCS: [walletbalance] Total balance=0.00525315 BTC
2019-05-07 14:24:41.671 [DBG] RPCS: [listchannels] fetched 0 channels from DB
2019-05-07 14:25:03.633 [DBG] RPCS: [walletbalance] Total balance=0.00525315 BTC
2019-05-07 14:25:03.881 [DBG] RPCS: [walletbalance] Total balance=0.00525315 BTC
2019-05-07 14:25:04.409 [DBG] RPCS: [listchannels] fetched 0 channels from DB
2019-05-07 14:25:05.635 [DBG] RPCS: [walletbalance] Total balance=0.00525315 BTC
2019-05-07 14:25:05.894 [DBG] RPCS: [walletbalance] Total balance=0.00525315 BTC
2019-05-07 14:25:06.475 [DBG] RPCS: [listchannels] fetched 0 channels from DB
2019-05-07 14:25:10.600 [ERR] SRVR: unable to start server: edge not found

2019-05-07 14:25:10.600 [INF] RPCS: Stopping RPC Server
2019-05-07 14:25:10.607 [INF] RPCS: Stopping SignRPC Sub-RPC Server
2019-05-07 14:25:10.614 [INF] RPCS: Stopping ChainRPC Sub-RPC Server
2019-05-07 14:25:10.615 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server
2019-05-07 14:25:10.615 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server
2019-05-07 14:25:10.627 [INF] LTND: Shutdown complete

[fluidvoice]

@halseth DB check is OK but compact fails...

I would try to run the bbolt tool:

~/raspiblitz/lnd $ sudo /home/admin/raspiblitz/lnd/bin/bbolt check /mnt/hdd/lnd/data/graph/mainnet/channel.db
OK
~/raspiblitz/lnd $ sudo /home/admin/raspiblitz/lnd/bin/bbolt compact -o ./new-channel.db /mnt/hdd/lnd/data/graph/mainnet/channel.db
fatal error: all goroutines are asleep - deadlock!

goroutine 1 [semacquire]:
sync.runtime_SemacquireMutex(0xc86228, 0x900)
/usr/local/go/src/runtime/sema.go:71 +0x2c
sync.(Mutex).Lock(0xc86224)
/usr/local/go/src/sync/mutex.go:134 +0x224
go.etcd.io/bbolt.(DB).Close(0xc86140, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/db.go:467 +0x38
panic(0x11b250, 0x20e210)
/usr/local/go/src/runtime/panic.go:522 +0x1a0
go.etcd.io/bbolt.(Bucket).Sequence(...)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:338
main.(CompactCommand).walkBucket.func1(0x5fc34b25, 0xa, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2114 +0xdc
go.etcd.io/bbolt.(Bucket).ForEach(0xfd85a0, 0xc39b68, 0x1, 0x1)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:388 +0xf8
main.(CompactCommand).walkBucket(0xc100c0, 0xfd85a0, 0xc0c5f0, 0x1, 0x1, 0x600d8f6f, 0xa, 0xa, 0x0, 0x0, ...)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2111 +0x124
main.(CompactCommand).walkBucket.func1(0x600d8f6f, 0xa, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2114 +0x158
go.etcd.io/bbolt.(Bucket).ForEach(0xc0ab80, 0xc39c40, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:388 +0xf8
main.(CompactCommand).walkBucket(0xc100c0, 0xc0ab80, 0x0, 0x0, 0x0, 0x600ce5da, 0xa, 0xa, 0x0, 0x0, ...)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2111 +0x124
main.(CompactCommand).walk.func1.1(0x600ce5da, 0xa, 0xa, 0xc0ab80, 0xc0ab80, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2093 +0x84
go.etcd.io/bbolt.(Tx).ForEach.func1(0x600ce5da, 0xa, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/tx.go:129 +0x70
go.etcd.io/bbolt.(Bucket).ForEach(0xc1238c, 0xc39d08, 0xc0e348, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:388 +0xf8
go.etcd.io/bbolt.(Tx).ForEach(0xc12380, 0xc7cd28, 0xd575c, 0x4)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/tx.go:128 +0x58
main.(CompactCommand).walk.func1(0xc12380, 0x13e1b8, 0xc12380)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2092 +0x54
go.etcd.io/bbolt.(DB).View(0xc86000, 0xc7cd6c, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/db.go:719 +0x84
main.(CompactCommand).walk(0xc100c0, 0xc86000, 0xc0a420, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2091 +0x54
main.(CompactCommand).compact(0xc100c0, 0xc86140, 0xc86000, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2021 +0x140
main.(CompactCommand).Run(0xc100c0, 0xc10040, 0x3, 0x4, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:1996 +0x360
main.(*Main).Run(0xc7cfac, 0xc10038, 0x4, 0x5, 0x0, 0x14f01)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:114 +0xc0c
main.main()
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:70 +0xa8

[wpaulino]

Did you run the bbolt compact command with lnd shut down?

[fluidvoice]

Did you run the bbolt compact command with lnd shut down?

I don't remember. Will have to try it again. I'm guessing it should be shut down?

[fluidvoice]

Did you run the bbolt compact command with lnd shut down?

@wpaulino retested and still fails with lnd shut down as seen here:
Actually it makes no difference if the lnd service is started or not,
bbolt compact always returns the "deadlock!" error.

~/raspiblitz/lnd $ sudo ls -al /mnt/hdd/lnd/data/graph/mainnet/channel.db
-rw------- 1 bitcoin bitcoin 83091456 May 7 22:19 /mnt/hdd/lnd/data/graph/mainnet/channel.db

~/raspiblitz/lnd $ sudo /home/admin/raspiblitz/lnd/bin/bbolt info /mnt/hdd/lnd/data/graph/mainnet/channel.db
Page Size: 4096

~/raspiblitz/lnd $ sudo systemctl status lnd.service
● lnd.service - LND Lightning Daemon
Loaded: loaded (/etc/systemd/system/lnd.service; enabled; vendor preset: enabled)
Active: inactive (dead) (Result: exit-code) since Tue 2019-05-07 22:19:26 BST; 2min 3
Process: 4191 ExecStart=/usr/local/bin/lnd --tor.active --tor.v2 --listen=127.0.0.1:97
Process: 4188 ExecStartPre=/home/admin/config.scripts/blitz.systemd.sh log lightning S
Main PID: 4191 (code=exited, status=1/FAILURE)

May 07 22:19:09 thunda systemd[1]: lnd.service: Unit entered failed state.
May 07 22:19:09 thunda systemd[1]: lnd.service: Failed with result 'exit-code'.
May 07 22:19:26 thunda systemd[1]: Stopped LND Lightning Daemon.

~/raspiblitz/lnd $ sudo /home/admin/raspiblitz/lnd/bin/bbolt check /mnt/hdd/lnd/data/graph/mainnet/channel.db
OK

~/raspiblitz/lnd $ export GOROOT=/usr/local/go && export PATH=$PATH:$GOROOT/bin && export GOPATH=/usr/local/gocode && export PATH=$PATH:$GOPATH/bin

~/raspiblitz/lnd $ rm -f ./new-channel.db

~/raspiblitz/lnd $ go version
go version go1.12.4 linux/arm

~/raspiblitz/lnd $ sudo /home/admin/raspiblitz/lnd/bin/bbolt compact -o ./new-channel.db /mnt/hdd/lnd/data/graph/mainnet/channel.db
fatal error: all goroutines are asleep - deadlock!

goroutine 1 [semacquire]:
sync.runtime_SemacquireMutex(0x1486228, 0x100)
/usr/local/go/src/runtime/sema.go:71 +0x2c
sync.(Mutex).Lock(0x1486224)
/usr/local/go/src/sync/mutex.go:134 +0x224
go.etcd.io/bbolt.(DB).Close(0x1486140, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/db.go:467 +0x38
panic(0x11b250, 0x20e210)
/usr/local/go/src/runtime/panic.go:522 +0x1a0
go.etcd.io/bbolt.(Bucket).Sequence(...)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:338
main.(CompactCommand).walkBucket.func1(0x5fc4db25, 0xa, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2114 +0xdc
go.etcd.io/bbolt.(Bucket).ForEach(0x16865e0, 0x1439b68, 0x1, 0x1)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:388 +0xf8
main.(CompactCommand).walkBucket(0x14100c0, 0x16865e0, 0x140c5f0, 0x1, 0x1, 0x600f1f6f, 0xa, 0xa, 0x0, 0x0, ...)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2111 +0x124
main.(CompactCommand).walkBucket.func1(0x600f1f6f, 0xa, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2114 +0x158
go.etcd.io/bbolt.(Bucket).ForEach(0x140ab80, 0x1439c40, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:388 +0xf8
main.(CompactCommand).walkBucket(0x14100c0, 0x140ab80, 0x0, 0x0, 0x0, 0x600e75da, 0xa, 0xa, 0x0, 0x0, ...)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2111 +0x124
main.(CompactCommand).walk.func1.1(0x600e75da, 0xa, 0xa, 0x140ab80, 0x140ab80, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2093 +0x84
go.etcd.io/bbolt.(Tx).ForEach.func1(0x600e75da, 0xa, 0xa, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/tx.go:129 +0x70
go.etcd.io/bbolt.(Bucket).ForEach(0x141238c, 0x1439d08, 0x140e348, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/bucket.go:388 +0xf8
go.etcd.io/bbolt.(Tx).ForEach(0x1412380, 0x147cd28, 0xd575c, 0x4)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/tx.go:128 +0x58
main.(CompactCommand).walk.func1(0x1412380, 0x13e1b8, 0x1412380)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2092 +0x54
go.etcd.io/bbolt.(DB).View(0x1486000, 0x147cd6c, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/go.etcd.io/[email protected]/db.go:719 +0x84
main.(CompactCommand).walk(0x14100c0, 0x1486000, 0x140a420, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2091 +0x54
main.(CompactCommand).compact(0x14100c0, 0x1486140, 0x1486000, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:2021 +0x140
main.(CompactCommand).Run(0x14100c0, 0x1410040, 0x3, 0x4, 0x0, 0x0)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:1996 +0x360
main.(*Main).Run(0x147cfac, 0x1410038, 0x4, 0x5, 0x0, 0x14f01)
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:114 +0xc0c
main.main()
/home/admin/raspiblitz/lnd/pkg/mod/github.com/etcd-io/[email protected]/cmd/bbolt/main.go:70 +0xa8

[wpaulino]

Looks like the tool isn't working on your database. Since we don't actually know if it's corrupted yet, we can just try skipping the edge not found error for now to see if you can get your node back up. Apply the following patch (make sure you have a clean state of the source code before doing so):

diff --git a/channeldb/graph.go b/channeldb/graph.go
index eaf3503c..b1b351b7 100644
--- a/channeldb/graph.go
+++ b/channeldb/graph.go
@@ -3025,7 +3025,9 @@ func (c *ChannelGraph) ChannelView() ([]EdgePoint, error) {
                edgeIndex, chanID,
            )
            if err != nil {
-               return err
+               log.Errorf("Unable to fetch edge info for "+
+                   "channel %v: %v", chanPoint, err)
+               return nil
            }

            pkScript, err := genMultiSigP2WSH(

Do you happen to know if the channel ed29da82fca43b0fffbf81fba5d93320854e926a8fa7e688d11a2df425a95127:0 belongs to your node?

[fluidvoice]

Looks like the tool isn't working on your database. Since we don't actually know if it's corrupted yet, we can just try skipping the edge not found error for now to see if you can get your node back up. Apply the following patch (make sure you have a clean state of the source code before doing so):

diff --git a/channeldb/graph.go b/channeldb/graph.go
index eaf3503c..b1b351b7 100644
--- a/channeldb/graph.go
+++ b/channeldb/graph.go
@@ -3025,7 +3025,9 @@ func (c *ChannelGraph) ChannelView() ([]EdgePoint, error) {
              edgeIndex, chanID,
          )
          if err != nil {
-             return err
+             log.Errorf("Unable to fetch edge info for "+
+                 "channel %v: %v", chanPoint, err)
+             return nil
          }

          pkScript, err := genMultiSigP2WSH(

Do you happen to know if the channel ed29da82fca43b0fffbf81fba5d93320854e926a8fa7e688d11a2df425a95127:0 belongs to your node?

When I built that previous patch (top of this issue) I was running rc1 and now am on rc2
lnd version 0.6.1-beta commit=v0.6.1-beta-rc2
Can I build the same way or I have to do something to special?
Can I just to make clean && make && make install ?

[fluidvoice]

Do you happen to know if the channel ed29da82fca43b0fffbf81fba5d93320854e926a8fa7e688d11a2df425a95127:0 belongs to your node?

No, I don't know.

[wpaulino]

As long as you're on a clean version of rc2 (no local changes), you can just follow https://github.com/lightningnetwork/lnd/issues/3025#issuecomment-489823348 again.

[fluidvoice]

I'm wondering now if this is worth the time. Already spent too long on this and 1) my wallet has small amount of $ and 2) I cannot find my mnemonic phrase when I created it.

[corbelantoine]

@fluidvoice Thanks for reporting! Can you try reproducing with this patch?

diff --git a/channeldb/graph.go b/channeldb/graph.go
index eaf3503c..9edd2955 100644
--- a/channeldb/graph.go
+++ b/channeldb/graph.go
@@ -3025,7 +3025,8 @@ func (c *ChannelGraph) ChannelView() ([]EdgePoint, error) {
              edgeIndex, chanID,
          )
          if err != nil {
-             return err
+             return fmt.Errorf("failed fetching edge info "+
+                 "for chanpoint %v: %v", chanPoint, err)
          }

          pkScript, err := genMultiSigP2WSH(
@@ -3456,7 +3457,8 @@ func fetchChanEdgeInfo(edgeIndex *bbolt.Bucket,

  edgeInfoBytes := edgeIndex.Get(chanID)
  if edgeInfoBytes == nil {
-     return ChannelEdgeInfo{}, ErrEdgeNotFound
+     return ChannelEdgeInfo{}, fmt.Errorf("chanID %x not found in "+
+         "edgeindex", chanID[:])
  }

  edgeInfoReader := bytes.NewReader(edgeInfoBytes)

I'm sorry for the late reply...
I finally could apply this patch and got this:

failed fetching edge info for chanpoint b1260773c1f864fbcb2996f4a51f544260dc11e0eeb3405d55529ff97ebfff03:17345975: chanID 473045022100bf09d7238ca8b7456004a529a10739d8b1b8c4c46dfd4236375e897443bd2d55022025bddbb75dc97b3d849c664cfee3c7c590fa0b3c89c6b4209975808710684dcc08adb7000aa00000000000005cc0bec50101009000000000000003e8000000000000003700000000000000370233502f6370758ede277d0ee5308a900feffeea29dbe9fc9593d1d0c30b2eb30e0800000000ce87b440 not found in edgeindex

[corbelantoine]

Running bbolt check channel.db gives me as a result:

7186 errors found
invalid value

running bbolt compact gives
fatal error: all goroutines are asleep - deadlock!

[wpaulino]

That definitely looks like database corruption. Were you ever able to start lnd successfully after upgrading to v0.6? If you did, you'll be able to recover your off-chain funds with the channel.backup file and seed. Otherwise, you'll only be able to recover on-chain with the seed.

[fluidvoice]

I brought up a 0.6-beta node on x86 Virtualbox with the same external HD containing the blockchain and LN data. And I get the same "edge not found" error. So at least we know in my case it's not specific to the Raspberry Pi.
LN log: https://termbin.com/cnod

[wpaulino]

It's still the same database file so moving to another system won't do much.

[fluidvoice]

It's still the same database file so moving to another system won't do much.

Yeah, it didn't surprise me, I just wanted to verify. What does "database" mean outside of the Bolt key/value store? Meaning, since bbolt check returned no errors, any idea where else this supposed corruption could be?

[wpaulino]

We haven't confirmed whether yours is corrupted as well, that comment above was meant for @corbelantoine. You should try the patch in https://github.com/lightningnetwork/lnd/issues/3025#issuecomment-490617588 and see what happens.

[corbelantoine]

That definitely looks like database corruption. Were you ever able to start lnd successfully after upgrading to v0.6? If you did, you'll be able to recover your off-chain funds with the channel.backup file and seed. Otherwise, you'll only be able to recover on-chain with the seed.

Yes I could but I made a payment in between so I'm not sure I've got the last version...
I tried and put data/chain/bitcoin/mainnet/channel.backup at data/graph/mainnet/channel.db

I got this error:
LTND: unable to open channeldb: invalid database

[wpaulino]

If you have a channel.backup, then you were able to successfully upgrade to v0.6. Follow this guide to recover your funds.

[corbelantoine]

Thank you.
Running
lncli restorechanbackup --multi_file .../data/chain/bitcoin/mainnet/channel.backup
got me
[lncli] unable to restore chan backups: rpc error: code = Unimplemented desc = unknown service lnrpc.Lightning

Maybe I should try running that on a clean lnd directory?

[wpaulino]

Yes, you'll need to create a new node from scratch and pass the backup as a flag to lncli create.

[corbelantoine]

panic: runtime error: invalid memory address or nil pointer dereference [recovered] panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x5b5ffc]

I got this after entering the seed on the lncli create --multi_file ...
It displayed the seed and crashed after that. There is a few more lines after that:

goroutine 1 [running]:
github.com/urfave/cli.HandleAction.func1(0x295bb70)
    /mnt/hdd/gocode/pkg/mod/github.com/urfave/[email protected]/app.go:472 +0x1f8
panic(0x680c40, 0xe07b20)
    /mnt/hdd/github/go/src/runtime/panic.go:513 +0x194
main.create(0x28261e0, 0x0, 0x0)
    /mnt/hdd/gocode/src/github.com/lightningnetwork/lnd/cmd/lncli/commands.go:1610 +0xd7c
main.actionDecorator.func1(0x28261e0, 0x0, 0x0)
    /mnt/hdd/gocode/src/github.com/lightningnetwork/lnd/cmd/lncli/commands.go:70 +0x24
reflect.Value.call(0x63ff80, 0x280f0d8, 0x13, 0x7214b3, 0x4, 0x295bb44, 0x1, 0x1, 0x28241c0, 0x29500e0, ...)
    /mnt/hdd/github/go/src/reflect/value.go:447 +0x368
reflect.Value.Call(0x63ff80, 0x280f0d8, 0x13, 0x295bb44, 0x1, 0x1, 0x722234, 0x0, 0x0)
    /mnt/hdd/github/go/src/reflect/value.go:308 +0x74
github.com/urfave/cli.HandleAction(0x63ff80, 0x280f0d8, 0x28261e0, 0x0, 0x0)
    /mnt/hdd/gocode/pkg/mod/github.com/urfave/[email protected]/app.go:481 +0x198
github.com/urfave/cli.Command.Run(0x722f79, 0x6, 0x0, 0x0, 0x0, 0x0, 0x0, 0x74c36c, 0x39, 0x0, ...)
    /mnt/hdd/gocode/pkg/mod/github.com/urfave/[email protected]/command.go:186 +0x6f8
github.com/urfave/cli.(*App).Run(0x291a000, 0x28240a0, 0x4, 0x4, 0x0, 0x0)
    /mnt/hdd/gocode/pkg/mod/github.com/urfave/[email protected]/app.go:235 +0x3ac
main.main()
    /mnt/hdd/gocode/src/github.com/lightningnetwork/lnd/cmd/lncli/main.go:307 +0x984

[wpaulino]

Ah I see, that is a bug unfortunately. Could you try restoring the backup _after_ re-creating your wallet and entering your seed?

[corbelantoine]

It worked for most of the channels but I still got one open.
The node is listing 0 channel and when I rerun the command I got
[lncli] unable to restore chan backups: rpc error: code = Unknown desc = unable to unpack chan backup: channel already exists

[fluidvoice]

It worked for most of the channels but I still got one open.
The node is listing 0 channel and when I rerun the command I got
[lncli] unable to restore chan backups: rpc error: code = Unknown desc = unable to unpack chan backup: channel already exists

Comments are much more useful when log output is included :)

[fluidvoice]

FYI two other Pi users hit this "edge not found" error here: https://github.com/rootzoll/raspiblitz/issues/575#issuecomment-491634865
and here: https://github.com/rootzoll/raspiblitz/issues/575#issuecomment-489427743
I think we have about 3 or 4 different Pi's now that hit this error. Sorry, I have not gotten around to building with that latest patch yet.

[corbelantoine]

It worked for most of the channels but I still got one open.
The node is listing 0 channel and when I rerun the command I got
[lncli] unable to restore chan backups: rpc error: code = Unknown desc = unable to unpack chan backup: channel already exists

Comments are much more useful when log output is included :)

Logs are too big to be included here :)

I am now resyncing a new lnd node (for the second time) and will try to run the command again on that one. Will update.

[fluidvoice]

Logs are too big to be included here :)

you can upload them like this: cat name_of_logfile | nc termbin.com 9999 and it will create just a short URL/link to the uploaded file on termbin.com Or upload them to pastebin.com same sorta thing.

[corbelantoine]

Here you go:
https://termbin.com/v4ps

I removed all the channel updates. The beginning of the file is where I run the command to restore from channel backup.
After seeing that all channels weren't closed (still) I tried to force close the channel myself by running
lncli closechannel txid outputindex --force
It crashed the node, now I can't start it anymore (end of the log file).

For example the channel 163613...64d6b1b4:1 is one of the channel that is mine but is still open.
Please note lncli listchannels was empty, I got the channel id from a lightning explorer.

[bjadel]

Hi,

I have the error "edge not found" too. The result of bbolt check on my channel.db is "OK". What can I do?

Cheers
Björn

[fluidvoice]

Hi,

I have the error "edge not found" too. The result of bbolt check on my channel.db is "OK". What can I do?

Cheers
Björn

Are you running Raspiblitz on a Pi? Have you ever run TOR on this node?

[fluidvoice]

we can just try skipping the edge not found error for now

@wpaulino What exactly is this "edge" that is not being found? I noticed the same error when running lncli getnetworkinfo:

[lncli] rpc error: code = Unknown desc = edge not found

[bjadel]

@fluidvoice Yes, I use Raspiblitz and yes I use Tor on my node. Currently, I have disabled Tor and the error persists.

[fluidvoice]

@fluidvoice Yes, I use Raspiblitz and yes I use Tor on my node. Currently, I have disabled Tor and the error persists.

@bjadel This matches what I experienced but I didn't know if it was a coincidence or what... after upgrading from Raspiblitz v1.1 to v1.2 it was working. Then I turned on TOR and it was still working for a while... then stopped working some time later. After that it never worked again even turning off TOR. Always getting this "edge not found" error.

[fluidvoice]

@wpaulino @halseth we have about seven Pi nodes now experiencing this "edge not found" error: https://github.com/rootzoll/raspiblitz/issues/562#issuecomment-493715389

[wpaulino]

@wpaulino What exactly is this "edge" that is not being found? I noticed the same error when running lncli getnetworkinfo:

@fluidvoice we attempt to look up a channel in the graph but it does not exist. Were you able to start up successfully after applying the most recent patch suggested to skip the error?

[fluidvoice]

Were you able to start up successfully after applying the most recent patch suggested to skip the error?

Not yet. I have not gotten around to building the patch.

[nolim1t]

Glad I'm not the only one experiencing this issue...

Also PI node too

[bjadel]

I created a new channel.db with "bbolt compact". A "bbolt check" returns that this is valid (ok). How do I restart lnd with this new database? Is it enough to just replace the old channel.db with the new one? Or is it necessary to delete caches or created help files or similar?

Thanks in advance
Björn

[fluidvoice]

Looks like the tool isn't working on your database. Since we don't actually know if it's corrupted yet, we can just try skipping the edge not found error for now to see if you can get your node back up. Apply the following patch (make sure you have a clean state of the source code before doing so):

diff --git a/channeldb/graph.go b/channeldb/graph.go
index eaf3503c..b1b351b7 100644
--- a/channeldb/graph.go
+++ b/channeldb/graph.go
@@ -3025,7 +3025,9 @@ func (c *ChannelGraph) ChannelView() ([]EdgePoint, error) {
              edgeIndex, chanID,
          )
          if err != nil {
-             return err
+             log.Errorf("Unable to fetch edge info for "+
+                 "channel %v: %v", chanPoint, err)
+             return nil
          }

          pkScript, err := genMultiSigP2WSH(

Do you happen to know if the channel ed29da82fca43b0fffbf81fba5d93320854e926a8fa7e688d11a2df425a95127:0 belongs to your node?

@wpaulino I now have the same "Raspiblitz" config running on both an x86/Intel node and in a VirtualBox VM. I've tested both with the same external HD (lnd+bitcoind data) connected and it still hits the "edge not found" error once LND finishes syncing. Being on x86 now should make it easy for you guys to give me patches to try out.

We now have eight different Pi nodes with this problem. One, not mine, has more 1+ BTC on it. Yeah #reckless Please advise.

[wpaulino]

@fluidvoice how often does the Raspiblitz setup call GetInfo? We've found a potential deadlock when polling GetInfo that could cause the daemon to not shut down cleanly, which would explain why users are experiencing this database issue.

[fluidvoice]

@fluidvoice how often does the Raspiblitz setup call GetInfo? We've found a potential deadlock when polling GetInfo that could cause the daemon to not shut down cleanly, which would explain why users are experiencing this database issue.

@wpaulino Sorry for the delay, just saw this.
There are a lot of different scripts which calls this. I need to look at each one.
_background.sh : every 10 secs
00infoLCD.sh : every 20 sec
These two scripts/processes are running all the time in the background while the user might do other things which also calls Getinfo so it's possible it gets called twice in less than 1 second.
Are lncli calls logged in debug-level to the log file so I can see when this is called accross all processes?

[wpaulino]

GetInfo isn't logged, most other RPCs are.

The deadlock would cause lnd not to shut down completely, so if the process gets force killed then it's possible to run into database corruption. The fix is now in master and will be included in the upcoming v0.7.0 release, so it should prevent nodes with this fix from running into this issue. For any other nodes without this fix that continue to run into this issue, there's not much we can do other than the recommended recovery process.

With that said, I'll go ahead and close this for now. Once v0.7.0 is out and most Raspiblitz nodes have upgraded, we can re-examine any further reports if the issue seems to persist.