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

Route not found despite direct channel #942

Closed
D4nte opened this issue Apr 11, 2019 · 17 comments
Closed

Route not found despite direct channel #942

D4nte opened this issue Apr 11, 2019 · 17 comments

Comments

@D4nte
Copy link

D4nte commented Apr 11, 2019

When trying to pay an invoice, I get route not found error.

I was connected to a well connected node I got the error.
So I decide to close all my channels and open a channel directly with the payee.

After doing so, waiting for channel to appear as NORMAL and waiting for the ln map syncing to happen, I tried the payment again and got route not found again.

I doubled checked and indeed, the invoice is for the node I have a channel opened to!

I expect the payment to work.

The issue happens systematically.

Trying to make a payment to Globee: 022c699df736064b51a33017abfc4d577d133f7124ac117d3d9f9633b6297a3b6a@lightning.globee.com:9735

Android Eclair, version 0.4.4

Here are the relevant logs:

2019-04-11 18:15:23,227 INFO  f.a.e.w.a.SendPaymentActivity  - initializing payment with invoice=lnbc16464u1pw2aaklpp50hn6sxqkj2l6nle6u906nczzqkpu4p4yqe47xuumnt335r5dkvwsdq2gakx7sn9v5cqzysxqzuygnw6m7dz9xmqzz5uhz2urx73jqd5cac62x5u0heuypgn2dpx6pc3vtdapqd5aqte7y6w9t8wc6azvphmfcjhvwc2cnncdf73pmwpengqdde45v
2019-04-11 18:15:24,790 INFO  f.a.eclair.wallet.App  - (lightning) sending 1646400000 msat for invoice PaymentRequest(lnbc,Some(MilliSatoshi(1646400000)),1554970335,022c699df736064b51a33017abfc4d577d133f7124ac117d3d9f9633b6297a3b6a,List(PaymentHash(7de7a8181692bfa9ff3ae15fa9e0420583ca86a4066be3739b9ae31a0e8db31d), Description(GloBee), MinFinalCltvExpiry(BitVector(10 bits, 0x240)), Expiry(BitVector(10 bits, 0xe10))),ByteVector(65 bytes, 0x44ddadf9a229b6010a9cb895c19bd1901b4c771a51a9c7df3c2051353426d071162dbd081b4e8179f134e2aceec6ba2606fb4e25763b0ac4e786a7d10edc1ccd00))
2019-04-11 18:15:24,815 INFO  f.a.eclair.router.Router  - finding a route 030909c76597132e4bb8e473bd98709c94414e4413259980cc0e088900195e311e->022c699df736064b51a33017abfc4d577d133f7124ac117d3d9f9633b6297a3b6a with assistedChannels= ignoreNodes= ignoreChannels= excludedChannels=
2019-04-11 18:15:24,816 INFO  f.a.eclair.router.Router  - finding a route with randomize=true params=RouteParams(true,21000,0.03,4,1008,Some(WeightRatios(0.15,0.35,0.5)))
2019-04-11 18:15:29,354 ERROR f.a.e.b.e.ElectrumClient  - server=MEADS.hopto.org/91.211.88.65:50002 sent error=Error(0,unsupported client: 3.3.4) while processing request=ServerVersion(3.3.4,1.4), disconnecting
@D4nte
Copy link
Author

D4nte commented Apr 11, 2019

The channel data:

{
 "nodeId": "022c699df736064b51a33017abfc4d577d133f7124ac117d3d9f9633b6297a3b6a",
 "channelId": "437a438d4933734c215a26a78d521b0ae97a25384dcbc0280d088125115c2887",
 "state": "NORMAL",
 "data": {
  "$type": "fr.acinq.eclair.channel.DATA_NORMAL",
  "commitments": {
   "localParams": {
    "nodeId": "030909c76597132e4bb8e473bd98709c94414e4413259980cc0e088900195e311e",
    "channelKeyPath": "m/514834697/1706086116'/815947026/765637151'",
    "dustLimitSatoshis": "546",
    "maxHtlcValueInFlightMsat": "5000000000",
    "channelReserveSatoshis": "24132",
    "htlcMinimumMsat": "1",
    "toSelfDelay": 2016,
    "maxAcceptedHtlcs": 30,
    "isFunder": true,
    "defaultFinalScriptPubKey": "a914ac2996592de24846f70e032dc0f0a89bce1e1fb887",
    "globalFeatures": "",
    "localFeatures": "02"
   },
   "remoteParams": {
    "nodeId": "022c699df736064b51a33017abfc4d577d133f7124ac117d3d9f9633b6297a3b6a",
    "dustLimitSatoshis": "573",
    "maxHtlcValueInFlightMsat": "2389131000",
    "channelReserveSatoshis": "24132",
    "htlcMinimumMsat": "1000",
    "toSelfDelay": 289,
    "maxAcceptedHtlcs": 483,
    "fundingPubKey": "02dc34670b630c29b6b2ad3447ed0cb01b2cabdb3df0be469e3106cff508fe50ec",
    "revocationBasepoint": "02b82a2255b623a9bedfaef52dbefd991d687f5ffa00afaff0c2f1fcc99d86ab9f",
    "paymentBasepoint": "031a66a35dab6618085c8bebbe6eb3e72ea74e45348bf24f06eebd57b883cc2266",
    "delayedPaymentBasepoint": "03b480eaabd1ed3e8ddd65319645d048ad0188120c9d82e6bf2ff19c07ad53ab12",
    "htlcBasepoint": "02ac9d45ced6e32c8de7ef7641a04d6fe077689e76c3420b94d869b14b5f47b513",
    "globalFeatures": "",
    "localFeatures": "81"
   },
   "channelFlags": 0,
   "localCommit": {
    "index": "2",
    "spec": {
     "htlcs": [
      
     ],
     "feeratePerKw": "12546",
     "toLocalMsat": "2413263000",
     "toRemoteMsat": "0"
    },
    "publishableTxs": {
     "commitTx": {
      "$type": "fr.acinq.eclair.transactions.Transactions.CommitTx",
      "input": {
       "outPoint": "437a438d4933734c215a26a78d521b0ae97a25384dcbc0280d088125115c2887:0",
       "txOut": {
        "amount": {
         "$type": "fr.acinq.bitcoin.Satoshi",
         "amount": "2413263"
        },
        "publicKeyScript": "0020a3fd926b1fa71fe038f6f174cef28e0f279edf430fb686f1abda0959237424d3"
       },
       "redeemScript": "5221026fbfe700fac2245e7a2940ebfc2ba24e97e84e8ba32f9e11de5c530e5b34cb182102dc34670b630c29b6b2ad3447ed0cb01b2cabdb3df0be469e3106cff508fe50ec52ae"
      },
      "tx": "02000000000101437a438d4933734c215a26a78d521b0ae97a25384dcbc0280d088125115c28870000000000d4735e800154af24000000000022002093c5154d04de3d03e452e16920c35953d8163eb5f6d4bcc3b816bfa8f587cde004004730440220285632fd555d323dfd637da4884241b813aff9dc6b248ba144c6991d447c59f902200997e8c31823164b9e9a3a1a7bb1dbd172b4164fcb1400d6e4d376cc4bc8d06c0147304402205d5cb7be5163830101644aa224dbec464217aa36b861bd6433f3caf85b4e6ad602203caf8d62c81f9e5ee9efdc756fbbb4a84ef8f728f4c70a8ed58cb2a1ca1b3b7001475221026fbfe700fac2245e7a2940ebfc2ba24e97e84e8ba32f9e11de5c530e5b34cb182102dc34670b630c29b6b2ad3447ed0cb01b2cabdb3df0be469e3106cff508fe50ec52ae4d717520"
     },
     "htlcTxsAndSigs": [
      
     ]
    }
   },
   "remoteCommit": {
    "index": "2",
    "spec": {
     "htlcs": [
      
     ],
     "feeratePerKw": "12546",
     "toLocalMsat": "0",
     "toRemoteMsat": "2413263000"
    },
    "txid": "e19c1b4caec448d643af44029d5c5ad034c9cf20ba8f1c07ba2444ae57fafef7",
    "remotePerCommitmentPoint": "02c90675e2d73a2a68d3292efd85f9aa4b59e461370b7251e45a934b8cde48d85b"
   },
   "localChanges": {
    "proposed": [
     
    ],
    "signed": [
     
    ],
    "acked": [
     
    ]
   },
   "remoteChanges": {
    "proposed": [
     
    ],
    "acked": [
     
    ],
    "signed": [
     
    ]
   },
   "localNextHtlcId": "0",
   "remoteNextHtlcId": "0",
   "originChannels": [
    
   ],
   "remoteNextCommitInfo": [
    1,
    "02dae04aebf90982abb165ad0bad2619793f9da7ab5eef32f024214f6cd4be6650"
   ],
   "commitInput": {
    "outPoint": "437a438d4933734c215a26a78d521b0ae97a25384dcbc0280d088125115c2887:0",
    "txOut": {
     "amount": {
      "$type": "fr.acinq.bitcoin.Satoshi",
      "amount": "2413263"
     },
     "publicKeyScript": "0020a3fd926b1fa71fe038f6f174cef28e0f279edf430fb686f1abda0959237424d3"
    },
    "redeemScript": "5221026fbfe700fac2245e7a2940ebfc2ba24e97e84e8ba32f9e11de5c530e5b34cb182102dc34670b630c29b6b2ad3447ed0cb01b2cabdb3df0be469e3106cff508fe50ec52ae"
   },
   "remotePerCommitmentSecrets": {
    "knownHashes": [
     [
      "-1",
      "c497d337ccc9d9952345f42b4dd2f72cbfdca0ab52bb322f44621ecca9c1a1f2"
     ]
    ],
    "lastIndex": [
     "281474976710654"
    ]
   },
   "channelId": "437a438d4933734c215a26a78d521b0ae97a25384dcbc0280d088125115c2887"
  },
  "shortChannelId": "571135x1186x0",
  "buried": true,
  "channelAnnouncement": [
   
  ],
  "channelUpdate": {
   "$type": "fr.acinq.eclair.wire.ChannelUpdate",
   "signature": "304402203527307975e0e8717bd227c60018856848d2b70830231450f3914dc23df4257902206c44bf4ede7132a30593c638c40156ac698f6004525c602abbc0e8be0c48022001",
   "chainHash": "6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000",
   "shortChannelId": "571135x1186x0",
   "timestamp": "1555025276",
   "messageFlags": 1,
   "channelFlags": 1,
   "cltvExpiryDelta": 144,
   "htlcMinimumMsat": "1000",
   "feeBaseMsat": "1000",
   "feeProportionalMillionths": "100",
   "htlcMaximumMsat": [
    "2413263000"
   ]
  },
  "localShutdown": [
   
  ],
  "remoteShutdown": [
   
  ]
 }
}

@araspitzu
Copy link
Contributor

You don't need a direct channel to the recipient, any well connected node should be able to route your payments to the destination. To be clear you're not able to pay any invoice? Have you waited for the sync to finish? You can trigger a fresh sync by wiping out the network db "Options > NetworkInfo > Reset Network Database".

@D4nte
Copy link
Author

D4nte commented Apr 12, 2019

I do understand that I do not need a direct channel but I really wanted to buy my thing so I tried to work around this bug by doing a direct channel.
Yes as stated I waited for the mapping of the lightning network to finish syncing and it still failed.
will try the reset.

@D4nte
Copy link
Author

D4nte commented Apr 12, 2019

Did a network database reset, waited for full sync, then did payment, same failure.

@araspitzu
Copy link
Contributor

Can you please post the complete logs of eclair from start to payment failed? (You can use pastebin to not pollute the issue here).

@kravens
Copy link

kravens commented Jun 9, 2019

I had exactly the same issue with a friend of mine who wanted to pay me over our direct channel:
image

@araspitzu
Copy link
Contributor

Can you share more details of the failure?

@kravens
Copy link

kravens commented Jun 10, 2019

Mobile client version: 0.3.1 on Android
Desktop client version 0.3 on Windows 10
Channel id: ? is now closed as it did not work...
Paste of my logfile during the failed invoice receives: https://pastebin.com/V9NXGAAj

Part where it failed:
_2019-05-09 20:10:49,512 INFO f.acinq.eclair.io.Server - connected to /92.53.65.44:54250
2019-05-09 20:10:49,564 INFO f.a.e.io.Authenticator n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - connection authenticated with 03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1@92.53.65.44:54250 direction=incoming
2019-05-09 20:10:49,564 INFO fr.acinq.eclair.io.Peer n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - using globalFeatures= and localFeatures=8a
2019-05-09 20:10:49,564 INFO fr.acinq.eclair.io.Peer n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - 03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 has features: initialRoutingSync=false channelRangeQueriesOptional=true channelRangeQueriesMandatory=false
2019-05-09 20:10:49,564 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - sending query_channel_range=QueryChannelRange(6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,0,2147483647)
2019-05-09 20:10:49,607 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - received query_channel_range=QueryChannelRange(6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,575133,4294392162)
2019-05-09 20:10:49,609 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - sending back reply_channel_range with 245 items for range=(575133, 4294392162)
2019-05-09 20:10:49,744 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - received reply_channel_range, we're missing 11 channel announcements/updates, format=0 useGzip=false
2019-05-09 20:10:49,793 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - received reply_channel_range, we're missing 45 channel announcements/updates, format=0 useGzip=false
2019-05-09 20:10:49,822 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - received reply_channel_range, we're missing 5 channel announcements/updates, format=0 useGzip=false
2019-05-09 20:10:49,855 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - received reply_channel_range, we're missing 0 channel announcements/updates, format=0 useGzip=false
2019-05-09 20:10:50,439 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - received query_short_channel_ids for 61 channel announcements, useGzip=false
2019-05-09 20:10:50,443 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - validating shortChannelId=542263x1620x1
2019-05-09 20:10:50,817 INFO f.a.eclair.router.Router - got validation result for shortChannelId=542263x1620x1 (awaiting=1 stash.nodes=0 stash.updates=0)
2019-05-09 20:10:50,817 WARN f.a.eclair.router.Router - ignoring shortChannelId=542263x1620x1 tx=6afe1d3b6e5c47090de4003bda9bd4ca12995be81315301229cd30d0b38e9384 (funding tx already spent)
2019-05-09 20:10:50,828 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - validating shortChannelId=548072x1362x0
2019-05-09 20:10:51,072 INFO f.a.eclair.router.Router - got validation result for shortChannelId=548072x1362x0 (awaiting=1 stash.nodes=0 stash.updates=0)
2019-05-09 20:10:51,072 WARN f.a.eclair.router.Router - ignoring shortChannelId=548072x1362x0 tx=4f713a566c179f37e69e5cae1aa0f200a2b058e53e47c3fddb442d0115aee1ab (funding tx already spent)
2019-05-09 20:10:51,077 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - validating shortChannelId=556779x1928x1
2019-05-09 20:10:51,081 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - validating shortChannelId=563363x2464x0
2019-05-09 20:10:51,084 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - validating shortChannelId=563365x2104x0
2019-05-09 20:10:51,088 INFO f.a.eclair.router.Router n:03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 - validating shortChannelId=563366x473x0

@araspitzu
Copy link
Contributor

@kravens I can't find any trace of route finding attempts in your logs, are you sure that's the relevant part? Also you're using an outdated version of the mobile app, please update to the latest 0.4.6.

@kravens
Copy link

kravens commented Jun 11, 2019

@araspitzu I'm the Desktop eclair user in this transaction, did not ask my friend for any logs of his smartphone. As far as I know he updated Eclair Mobile to the latest version last week (presumed that was 0.3.1, could be 0.4.6). Mobile user was: 03ec201d396cc68d34360a13eee019189860006db990bfe85791f42fa9c00e8df1 as I pasted in the section above, we were only able to transact 1/3 of the channel as all large amounts failed to get through.

@D4nte
Copy link
Author

D4nte commented Jun 20, 2019

I tried again to pay to the same node and it worked this time.... Happy to close or handover to @kravens ...

@araspitzu
Copy link
Contributor

@kravens are you sure you have enough balance on your side to send the payment?

@kravens
Copy link

kravens commented Jun 24, 2019

I'm sure the balance was sufficient, was trying to receive 170 000 sats over a +300 000 sat incoming channel. We tried several times with smaller and smaller amounts, but only the first 100 000 sats could be transfered and later settled on-chain:
6/9/19 20:41 Confirmed
txid: e1561a989c446d30362b835cd667d968f80201dac5fb0c49a8e9d71504eb94d6

@araspitzu
Copy link
Contributor

@kravens would you mind describing the issue again? It's not clear if you had troubles sending or receiving (D4nte had troubles sending), if the problem is different is better to open a new issue.

@kravens
Copy link

kravens commented Jun 25, 2019

@araspitzu
Me: | Friend:
Desktop Eclair v0.3 on W10 | Mobile eclair v0.4.6 on android
Channel balance 0 sat | Channel balance: 330026 sat
Request 300000 sat | Failed payment / error (issue 1)
Request 170000 sat | Failed payment / error (issue 2)
Request 100000 sat | Succesfull payment! (the exception)
Request 100000 sat (2x) | Failed payment / error (issue 3)
-> Problem receiving | Problem sending ->
Closed channel | Received remaining balance

@araspitzu
Copy link
Contributor

@kravens
According to your description it seems to be a bug, the desktop eclair should be able to receive over the direct channel with the phone. I will try to reproduce it but i'm afraid it depends on some other circumstances that are not listed in your description, please attach any other log (from mobile) or information that might be useful for debugging.

@t-bast
Copy link
Member

t-bast commented Aug 22, 2019

We fixed a routing issue in #1090 that was likely the reason why your payments were failing.
I'm closing this issue, if you still experience payment failures feel free to re-open!

@t-bast t-bast closed this as completed Aug 22, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants