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.

Sign up for GitHub

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

Jump to bottom

phoenix fails to pay invoice if any routing hint has low receive-capacity #1725

Closed
SomberNight opened this issue Mar 8, 2021 · 5 comments · Fixed by #1726
Closed

phoenix fails to pay invoice if any routing hint has low receive-capacity #1725

SomberNight opened this issue Mar 8, 2021 · 5 comments · Fixed by #1726
Assignees
@t-bast

Comments

@SomberNight
Copy link

SomberNight commented Mar 8, 2021 •
edited
Loading

I am testing sending/receiving trampoline payments between electrum and eclair on mainnet.
TL;DR: if an invoice contains two routing hints and one of those channels have very low capacity, phoenix fails to pay it;
but if that routing hint is removed, phoenix succeeds in paying

Scenario1:

  • electrum creates invoice1 with two routing hints ("r" tag), (the channels are with unrelated well-connected nodes, but not with the "ACINQ" trampoline node)
    • payment_hash for invoice1: dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d
  • invoice1 is for an amount of 200_000 sat, channel1 can receive ~1_100_000 sat, channel2 can receive ~20_000 sat
  • phoenix tries to pay invoice1
  • it varies between attempts, but electrum sees 2-3 htlcs, all on channel1
    • for example, during one attempt, it sees 3 htlcs, with amounts: 36 ksat, 1.5 ksat, 85 ksat
      • for this attempt, electrum sees first HTLC get added around 2021-03-08 16:23:54 CET
    • the htlcs don't sum up to the invoice amount of 200 ksat, and after 2 minutes, electrum fails them with MPP_TIMEOUT
  • outcome:
    • ACTUAL: payment fails
    • EXPECTED: trampoline figures out that channel1 has sufficient capacity, and payment succeeds

Scenario2:

  • I modify the code of electrum to only include a single routing hint, for channel1
  • electrum creates invoice2 with a just one routing hint, for the large channel
    • payment_hash for invoice2: 34afe119523ab7d4d0425b56bc04011feb285bcd9c79fe1c34c6ee2f34ac40a9
  • invoice2 is for an amount of 200_000 sat, channel1 can receive ~1_100_000
  • phoenix tries to pay invoice2
  • electrum sees a single htlc for the full amount of 200 ksat
    • for this attempt, electrum sees HTLC get added around 2021-03-08 16:56:39 CET
  • payment succeeds

I can also reproduce with electrum1 trying to pay electrum2, using trampoline (that runs eclair), "pay to legacy".

Scenario3:

  • electrum1 creates invoice1 with two routing hints ("r" tag), (the channels are with unrelated well-connected nodes, but not with the "ACINQ" trampoline node)
    • payment_hash for invoice1: dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d
  • invoice1 is for an amount of 200_000 sat, channel1 can receive ~1_100_000 sat, channel2 can receive ~20_000 sat
  • electrum2 tries to pay invoice1, using "Electrum trampoline" node (which runs eclair)
  • it varies between attempts, but electrum1 sees 2-3 htlcs, all on channel1
    • the htlcs don't sum up to the invoice amount of 200 ksat, and after 2 minutes, electrum1 fails them with MPP_TIMEOUT
  • outcome:
    • ACTUAL: payment fails
    • EXPECTED: trampoline figures out that channel1 has sufficient capacity, and payment succeeds
log of trampoline node, for scenario3 
2021-03-08 17:40:55,222 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6516c4e2 - relaying payment relayId=6516c4e2-d3c7-4598-8436-73d2518ab121
2021-03-08 17:40:56,779 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6516c4e2 - completed incoming multi-part payment with parts=2 paidAmount=200000000 msat
2021-03-08 17:40:56,779 WARN  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6516c4e2 - rejecting trampoline payment reason=TrampolineFeeInsufficient
2021-03-08 17:41:00,618 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6dd01b04 - relaying payment relayId=6dd01b04-58fa-4394-9e40-56e010565c66
2021-03-08 17:41:01,677 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6dd01b04 - completed incoming multi-part payment with parts=2 paidAmount=200021000 msat
2021-03-08 17:41:01,677 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6dd01b04 - relaying trampoline payment (amountIn=200021000 msat expiryIn=CltvExpiry(674461) amountOut=200000000 msat expiryOut=CltvExpiry(673885))
2021-03-08 17:41:01,678 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6dd01b04 i:6dd01b04 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:01,678 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6dd01b04 i:6dd01b04 - finding routes with randomize=false params=RouteParams(false,0 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:01,678 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6dd01b04 i:6dd01b04 - router error: route not found
2021-03-08 17:41:01,678 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:6dd01b04 i:6dd01b04 - multi-part payment failed
2021-03-08 17:41:06,609 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:cf5fb8d8 - relaying payment relayId=cf5fb8d8-cd50-473d-a4c4-bbd0b748b4a4
2021-03-08 17:41:06,711 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:cf5fb8d8 - completed incoming multi-part payment with parts=2 paidAmount=200023000 msat
2021-03-08 17:41:06,711 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:cf5fb8d8 - relaying trampoline payment (amountIn=200023000 msat expiryIn=CltvExpiry(674461) amountOut=200000000 msat expiryOut=CltvExpiry(673885))
2021-03-08 17:41:06,712 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:cf5fb8d8 i:cf5fb8d8 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:06,712 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:cf5fb8d8 i:cf5fb8d8 - finding routes with randomize=false params=RouteParams(false,2000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:06,795 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:cf5fb8d8 i:cf5fb8d8 - router error: route not found
2021-03-08 17:41:06,795 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:cf5fb8d8 i:cf5fb8d8 - multi-part payment failed
2021-03-08 17:41:12,239 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:8af14eb7 - relaying payment relayId=8af14eb7-a5f4-4bff-b506-f495d9c4a5f3
2021-03-08 17:41:12,334 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:8af14eb7 - completed incoming multi-part payment with parts=2 paidAmount=200105000 msat
2021-03-08 17:41:12,334 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:8af14eb7 - relaying trampoline payment (amountIn=200105000 msat expiryIn=CltvExpiry(674461) amountOut=200000000 msat expiryOut=CltvExpiry(673885))
2021-03-08 17:41:12,334 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:8af14eb7 i:8af14eb7 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:12,334 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:8af14eb7 i:8af14eb7 - finding routes with randomize=false params=RouteParams(false,84000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:12,424 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:8af14eb7 i:8af14eb7 - router error: route not found
2021-03-08 17:41:12,424 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:8af14eb7 i:8af14eb7 - multi-part payment failed
2021-03-08 17:41:16,851 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 - relaying payment relayId=c97b7b49-3338-4b7b-99ac-13879a0a92b9
2021-03-08 17:41:17,799 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 - completed incoming multi-part payment with parts=2 paidAmount=200207000 msat
2021-03-08 17:41:17,800 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 - relaying trampoline payment (amountIn=200207000 msat expiryIn=CltvExpiry(674461) amountOut=200000000 msat expiryOut=CltvExpiry(673885))
2021-03-08 17:41:17,801 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:17,801 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes with randomize=false params=RouteParams(false,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:17,893 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - 1 routes found (attempt=1/5)
2021-03-08 17:41:17,893 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:709b3fd4 - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:41:22,450 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:709b3fd4 - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:41:22,450 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:709b3fd4 - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221677,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(200145420 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:41:22,450 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:709b3fd4 - too many failed attempts, failing the payment
2021-03-08 17:41:22,451 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:22,452 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:22,635 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - 1 routes found (attempt=2/5)
2021-03-08 17:41:22,635 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:16bcd52f - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:41:26,787 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:16bcd52f - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:41:26,787 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:16bcd52f - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221682,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(200145420 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:41:26,787 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:16bcd52f - too many failed attempts, failing the payment
2021-03-08 17:41:26,788 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:26,788 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:26,971 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - 1 routes found (attempt=3/5)
2021-03-08 17:41:26,972 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:2a3fd6e2 - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:41:30,836 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:2a3fd6e2 - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:41:30,836 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:2a3fd6e2 - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221686,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(200145420 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:41:30,836 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:2a3fd6e2 - too many failed attempts, failing the payment
2021-03-08 17:41:30,838 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:30,838 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:31,024 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - 1 routes found (attempt=4/5)
2021-03-08 17:41:31,024 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:d4dac407 - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:41:34,811 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:d4dac407 - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:41:34,811 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:d4dac407 - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221690,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(200145420 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:41:34,811 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:d4dac407 - too many failed attempts, failing the payment
2021-03-08 17:41:34,812 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:34,812 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:34,997 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - 1 routes found (attempt=5/5)
2021-03-08 17:41:34,997 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:aa72f79a - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:41:38,985 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:aa72f79a - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:41:38,985 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:aa72f79a - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221694,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(200145420 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:41:38,985 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:aa72f79a - too many failed attempts, failing the payment
2021-03-08 17:41:38,985 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:c97b7b49 i:c97b7b49 - multi-part payment failed
2021-03-08 17:41:44,068 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce - relaying payment relayId=020d1cce-7656-4165-9a91-109c40dd935f
2021-03-08 17:41:44,474 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce - completed incoming multi-part payment with parts=2 paidAmount=200207000 msat
2021-03-08 17:41:44,474 INFO  f.a.e.p.r.NodeRelay PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce - relaying trampoline payment (amountIn=200207000 msat expiryIn=CltvExpiry(674461) amountOut=200000000 msat expiryOut=CltvExpiry(673885))
2021-03-08 17:41:44,475 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:44,475 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes with randomize=false params=RouteParams(false,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:44,567 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - 1 routes found (attempt=1/5)
2021-03-08 17:41:44,567 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:e2bd1245 - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:41:51,737 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:e2bd1245 - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:41:51,737 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:e2bd1245 - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221704,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(200145420 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:41:51,737 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:e2bd1245 - too many failed attempts, failing the payment
2021-03-08 17:41:53,138 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:53,138 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:53,231 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - 2 routes found (attempt=2/5)
2021-03-08 17:41:53,231 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:d48d5a3c - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:41:53,231 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:79b04c05 - route found: attempt=1/1 route=03cde60a6323f7122d5178255766e38114b4722ede08f7c9e0c5df9b912cc201d6->02004c625d622245606a1ea2c1c69cfb4516b703b47945a3647713c05fe4aaeb1c->INVOICE_PUBKEY_REDACTED channels=657915x1465x1->649461x793x1->LARGE_CHANNEL_1_SCID
2021-03-08 17:41:57,650 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:d48d5a3c - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:41:57,650 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:d48d5a3c - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221713,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(200145420 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:41:57,650 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:d48d5a3c - too many failed attempts, failing the payment
2021-03-08 17:41:58,405 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:41:58,405 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:41:58,582 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - 1 routes found (attempt=3/5)
2021-03-08 17:41:58,583 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:3987f6c2 - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:42:02,557 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:3987f6c2 - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:42:02,558 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:3987f6c2 - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221718,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(126091177 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:42:02,558 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:3987f6c2 - too many failed attempts, failing the payment
2021-03-08 17:42:03,704 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:42:03,705 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:42:03,883 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - 1 routes found (attempt=4/5)
2021-03-08 17:42:03,883 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:178ad9a6 - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:42:07,608 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:178ad9a6 - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:42:07,608 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:178ad9a6 - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221723,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(126091177 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:42:07,608 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:178ad9a6 - too many failed attempts, failing the payment
2021-03-08 17:42:08,326 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1->INVOICE_PUBKEY_REDACTED with assistedChannels=SMALL_CHANNEL_2_SCID,LARGE_CHANNEL_1_SCID ignoreNodes= ignoreChannels= excludedChannels=
2021-03-08 17:42:08,326 INFO  f.a.eclair.router.Router PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - finding routes with randomize=true params=RouteParams(true,186000 msat,0.0,6,CltvExpiryDelta(432),Some(WeightRatios(0.15,0.35,0.5)),MultiPartParams(15000000 msat,6))
2021-03-08 17:42:08,499 INFO  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - 1 routes found (attempt=5/5)
2021-03-08 17:42:08,499 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:9e415f81 - route found: attempt=1/1 route=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6->INVOICE_PUBKEY_REDACTED channels=660321x1333x0->SMALL_CHANNEL_2_SCID
2021-03-08 17:42:13,136 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:9e415f81 - received an error message from nodeId=0284a249ee165723f01ae08dc340f9f60bcbce8dda2140401f1bd7548ef11dd5e6 (failure=TemporaryChannelFailure(ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))))
2021-03-08 17:42:13,137 INFO  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:9e415f81 - got a new update for shortChannelId=SMALL_CHANNEL_2_SCID: old=ChannelUpdate(00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000,0000000000000000000000000000000000000000000000000000000000000000,SMALL_CHANNEL_2_SCID,1615221728,1,0,CltvExpiryDelta(40),0 msat,20 msat,727,Some(126091177 msat),ByteVector(empty)) new=ChannelUpdate(e572abc13b19130fbe759bff8bfe54bfb8045d61fe7b22b34e5a107538ee61ba7c65b4d6a6881db7589f92b6a5f54c963f3aedcbcc17b0ede6a2ee509441bdd9,6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d6190000000000,SMALL_CHANNEL_2_SCID,1606521605,1,0,CltvExpiryDelta(40),1000 msat,20 msat,727,Some(3973565000 msat),ByteVector(empty))
2021-03-08 17:42:13,137 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:9e415f81 - too many failed attempts, failing the payment
2021-03-08 17:43:57,815 WARN  f.a.e.p.s.PaymentLifecycle PAY h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:79b04c05 - received an error message from target nodeId=INVOICE_PUBKEY_REDACTED, failing the payment (failure=PaymentTimeout)
2021-03-08 17:43:57,816 WARN  f.a.e.p.s.MultiPartPaymentLifecycle PAY n:INVOICE_PUBKEY_REDACTED h:dc9fa67600848be48c29d5d3c46eb0a881f883f15d2de57080ea0b711f95144d p:020d1cce i:020d1cce - multi-part payment failed
@t-bast
Copy link
Member

t-bast commented Mar 8, 2021

What version of eclair is your trampoline node running?
We fixed a bug that looks very similar to that a month ago in 0127ace

@SomberNight
Copy link
Author

I've added timestamps and payment_hashes.

@t-bast
Copy link
Member

t-bast commented Mar 8, 2021

Ok this is a bit similar to the bug we fixed earlier but not completely the same, we should propagate more information about the error from PaymentLifecycle to its parent MultiPartPaymentLifecycle, I'd been holding off on that...

@SomberNight
Copy link
Author

scenario 3 trampoline is running eclair tag v0.5.1, 98bb7be70a4fc96242409b90fbf1ec9c5ff470e6
note that the other scenarios are using phoenix and hence the ACINQ node

@t-bast
Copy link
Member

t-bast commented Mar 8, 2021

Ok I think this line is the culprit:

eclair/eclair-core/src/main/scala/fr/acinq/eclair/payment/PaymentEvents.scala

Line 170 in ea8f940

// We were using an outdated channel update, we should retry with the new one and nobody should be penalized.

We should check whether the error is specifically TemporaryChannelFailure, and if that's the case we must ignore this channel, which we're not doing at the moment.

Thanks for the report, I'll fix that soon.

@t-bast t-bast self-assigned this Mar 8, 2021
t-bast added a commit that referenced this issue Mar 9, 2021
@t-bast
Better handling of TemporaryChannelFailure
06f1b30 
When a node returns a TemporaryChannelFailure, we should ignore this channel
when retrying. In some cases (such as channels from routing hints) this was
not correctly handled.

Fixes #1725
@t-bast t-bast mentioned this issue Mar 9, 2021
Merged
t-bast added a commit that referenced this issue Mar 10, 2021
@t-bast
Better handling of TemporaryChannelFailure (#1726)
2772138 
When a node returns a TemporaryChannelFailure, we should ignore this channel
when retrying. In some cases (such as channels from routing hints) this was
not correctly handled.

Fixes #1725
tompro pushed a commit to tompro/eclair that referenced this issue Mar 21, 2021
@t-bast @tompro
Better handling of TemporaryChannelFailure (ACINQ#1726)
1a5e61c 
When a node returns a TemporaryChannelFailure, we should ignore this channel
when retrying. In some cases (such as channels from routing hints) this was
not correctly handled.

Fixes ACINQ#1725
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@t-bast t-bast

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Better handling of TemporaryChannelFailure ACINQ/eclair
2 participants
@SomberNight @t-bast