findroute fails in eclair on `v0.3.1`

[Christewart]

Hi all,

I'm experiencing some weird behavior with the latest eclair release on a node we upgraded from 2.9. findroute appears to crash eclair and force it to restart. The findroute command we are running is

$node1 findroute --invoice=lnbc1pw5nhvjpp5pltpz5g9ty630vexwrg9d3r3yelyz5z6f7qtvsg65c5gsv2teyrqdqqcqzysnh5r2vu20m0ed5nwtkv3e30zxku879qxyf5uy4c4jjr3krv9r7gz0vf8kj3zwgfsk9g52we9paxjgg74w5wz0vlw2ggzyr4uv44ggdqqdasyqt --amountMsat=10
route not found

$node1 parseinvoice --invoice=lnbc1pw5nhvjpp5pltpz5g9ty630vexwrg9d3r3yelyz5z6f7qtvsg65c5gsv2teyrqdqqcqzysnh5r2vu20m0ed5nwtkv3e30zxku879qxyf5uy4c4jjr3krv9r7gz0vf8kj3zwgfsk9g52we9paxjgg74w5wz0vlw2ggzyr4uv44ggdqqdasyqt
{
  "prefix": "lnbc",
  "timestamp": 1565121938,
  "nodeId": "0290944396978e825466050aba1958bb8ceb67116c7fc2cc01ce230226d14588b9",
  "serialized": "lnbc1pw5nhvjpp5pltpz5g9ty630vexwrg9d3r3yelyz5z6f7qtvsg65c5gsv2teyrqdqqcqzysnh5r2vu20m0ed5nwtkv3e30zxku879qxyf5uy4c4jjr3krv9r7gz0vf8kj3zwgfsk9g52we9paxjgg74w5wz0vlw2ggzyr4uv44ggdqqdasyqt",
  "description": "",
  "paymentHash": "0fd6115105593517b32670d056c471267e41505a4f80b6411aa62888314bc906",
  "minFinalCltvExpiry": 144
}

the error showing up in ~/.eclair/eclair.log is

2019-08-07 00:28:22,387 INFO  f.a.eclair.router.Router  - finding a route 038bdb5538a4e415c42f8fb09750729752c1a1800d321f4bb056a9f582569fbf8e->0290944396978e825466050aba1958bb8ceb67116c7fc2cc01ce230226d14588b9 with assistedChannels= ignoreNodes= ignoreChannels= excludedChannels=
2019-08-07 00:28:22,387 INFO  f.a.eclair.router.Router  - finding a route with randomize=true params=RouteParams(true,21000,0.03,6,1008,Some(WeightRatios(0.15,0.35,0.5)))
2019-08-07 00:28:22,388 ERROR f.a.e.Setup$$anonfun$bootstrap$2$$anonfun$apply$15$$anonfun$apply$18$$anonfun$apply$19$$anonfun$apply$20$$anonfun$apply$21$$anon$1  - API call failed with cause=route not foundfr.acinq.eclair.router.RouteNotFound$: route not found
        at fr.acinq.eclair.router.RouteNotFound$.<clinit>(RouterExceptions.scala)
        at fr.acinq.eclair.router.Router$$anonfun$findRoute$1.apply(Router.scala:880)
        at fr.acinq.eclair.router.Router$$anonfun$findRoute$1.apply(Router.scala:865)
        at scala.util.Try$.apply(Try.scala:192)
        at fr.acinq.eclair.router.Router$.findRoute(Router.scala:865)
        at fr.acinq.eclair.router.Router$$anonfun$findRoute$1.apply(Router.scala:879)
        at fr.acinq.eclair.router.Router$$anonfun$findRoute$1.apply(Router.scala:865)
        at scala.util.Try$.apply(Try.scala:192)
        at fr.acinq.eclair.router.Router$.findRoute(Router.scala:865)
        at fr.acinq.eclair.router.Router$$anonfun$1.applyOrElse(Router.scala:420)
        at fr.acinq.eclair.router.Router$$anonfun$1.applyOrElse(Router.scala:166)
        at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:36)
        at akka.actor.FSM$class.processEvent(FSM.scala:663)
        at fr.acinq.eclair.router.Router.processEvent(Router.scala:110)
        at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:657)
        at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:651)
        at akka.actor.Actor$class.aroundReceive(Actor.scala:502)
        at fr.acinq.eclair.router.Router.fr$acinq$eclair$FSMDiagnosticActorLogging$$super$aroundReceive(Router.scala:110)
        at fr.acinq.eclair.FSMDiagnosticActorLogging$class.aroundReceive(FSMDiagnosticActorLogging.scala:38)
        at fr.acinq.eclair.router.Router.aroundReceive(Router.scala:110)
        at akka.actor.ActorCell.receiveMessage(ActorCell.scala:526)
        at akka.actor.ActorCell.invoke(ActorCell.scala:495)
        at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:257)
        at akka.dispatch.Mailbox.run(Mailbox.scala:224)

2019-08-07 00:28:34,299 INFO  fr.acinq.eclair.io.Peer  n:024a8228d764091fce2ed67e1a7404f83e38ea3c7cb42030a2789e73cf3b341365 - sent announcements to 024a8228d764091fce2ed67e1a7404f83e38ea3c7cb42030a2789e73cf3b341365: channels=0 updates=40 nodes=0
2019-08-07 00:28:35,299 INFO  fr.acinq.eclair.io.Peer  n:0290944396978e825466050aba1958bb8ceb67116c7fc2cc01ce230226d14588b9 - sent announcements to 0290944396978e825466050aba1958bb8ceb67116c7fc2cc01ce230226d14588b9: channels=0 updates=40 nodes=0

The hard error when the route is not found (we have an active channel with this node, which i will paste for completeness later).

The open channel with this peer can be queries within eclair itself with this command:

$node1 channels --nodeId=0290944396978e825466050aba1958bb8ceb67116c7fc2cc01ce230226d14588b9
[
  {
    "nodeId": "0290944396978e825466050aba1958bb8ceb67116c7fc2cc01ce230226d14588b9",
    "channelId": "354e9b87f6438b1850096c88bebddd73fca712e3b1d6e99a2ff0a07e50927e47",
    "state": "NORMAL",
    "data": { ... }
]

The version we are on

/usr/bin/java  -jar /home/ubuntu/eclair/eclair-node-0.3.1-6906ecb.jar

[Christewart]

One thing I am realizing is the node we are peering with is a lnd node with version v0.5.2, which is a very old node. Perhaps there is some incompatibility there, I will investigate in the morning.

[araspitzu]

Hi Chris, I see you're trying to send a tiny amount 10 msat have you checked if the htlcMinimumMsat of your channel is small enough to accomodate it? The router checks those values against the amount you're trying to send and if it's not compatible it will throw a RouteNotFound.

If the only channel you have with 0290944396978e825466050aba1958bb8ceb67116c7fc2cc01ce230226d14588b9 is 587695x1975x1 then your htlcMinimumMsat is set to 1000 and is too high to send 10 msat.

[Christewart]

That is what it was. It would be great if you guys could at least add logs to indicate things like these and as part of #1074, or even better make the API return indicative routing failure messages