Implement custom debug for PathBuildingHop #1318

jurvis · 2022-02-18T04:18:20Z

Re-opened of #1300
This PR is an attempt at #1233.

The goal here is to clean up the existing output for PathBuildingHop, and surface only the properties we care about.

Demo

This is the new output for PathBuildingHop (ran via routing::router::tests::simple_route_test):

Found a path back to us from the target with 2 hops contributing up to 100 msat: 
[(PathBuildingHop: node_id: NodeId(02531fe6068134503d2723133227c867ac8fa6c83c537e9a44c3c5bdbdcb1fe337), short_channel_id: 2, fee_msat: 100, path_penalty_msat: 0, path_htlc_minimum_msat: 4294967295, cltv_expiry_delta: 83, [8]), (PathBuildingHop: node_id: NodeId(03462779ad4aad39514614751a71085f2f10e1c7a593e4e030efb5b8721ce55b0b), short_channel_id: 4, fee_msat: 100, path_penalty_msat: 0, path_htlc_minimum_msat: 0, cltv_expiry_delta: 65, [32])]

Some Questions

I am somewhat dissatisfied with the current implementation because the print-out just doesn't seem very ergonomic. Ideally, we'll be able to have the print-out be something closer to what we have for logging routes. Where instead of printing out the Vec, we'll be able to show:

Found a path back to us from the target with 2 hops contributing up to 100 msat: 
  node_id: 02531fe6068134503d2723133227c867ac8fa6c83c537e9a44c3c5bdbdcb1fe337, short_channel_id: 2, fee_msat: 100, path_penalty_msat: 0, path_htlc_minimum_msat: 4294967295, cltv_expiry_delta: 8
  node_id: 03462779ad4aad39514614751a71085f2f10e1c7a593e4e030efb5b8721ce55b0b, short_channel_id: 4, fee_msat: 100, path_penalty_msat: 0, path_htlc_minimum_msat: 0, cltv_expiry_delta: 65

There is an opportunity for improvement here by adding a macro to macro_logger that does a clean Display of PaymentPath, but that will mean having to exposing fields in PathBuildingHop and PaymentPath to be public, which I am not sure we want.

Any thoughts on this will be appreciated!

codecov-commenter · 2022-02-18T04:44:13Z

Codecov Report

Merging #1318 (e73b8a2) into main (b8e9e8b) will decrease coverage by 0.00%.
The diff coverage is 100.00%.

❗ Current head e73b8a2 differs from pull request most recent head 1ce2b92. Consider uploading reports for the commit 1ce2b92 to get more accurate results

@@            Coverage Diff             @@
##             main    #1318      +/-   ##
==========================================
- Coverage   90.50%   90.49%   -0.01%     
==========================================
  Files          71       72       +1     
  Lines       39042    39631     +589     
==========================================
+ Hits        35336    35866     +530     
- Misses       3706     3765      +59

Impacted Files	Coverage Δ
lightning/src/routing/router.rs	`91.96% <100.00%> (+0.17%)`	⬆️
lightning/src/chain/keysinterface.rs	`93.58% <0.00%> (-2.29%)`	⬇️
lightning/src/util/scid_utils.rs	`98.37% <0.00%> (-1.63%)`	⬇️
lightning/src/util/config.rs	`46.80% <0.00%> (-1.02%)`	⬇️
lightning/src/routing/network_graph.rs	`89.52% <0.00%> (-0.46%)`	⬇️
lightning/src/ln/onion_utils.rs	`95.33% <0.00%> (-0.31%)`	⬇️
lightning/src/ln/functional_tests.rs	`97.05% <0.00%> (-0.18%)`	⬇️
lightning/src/ln/peer_channel_encryptor.rs	`94.98% <0.00%> (-0.16%)`	⬇️
lightning/src/ln/channel.rs	`89.24% <0.00%> (-0.08%)`	⬇️
lightning/src/ln/msgs.rs	`85.84% <0.00%> (-0.05%)`	⬇️
... and 10 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update b8e9e8b...1ce2b92. Read the comment docs.

TheBlueMatt · 2022-02-18T16:31:43Z

lightning/src/routing/router.rs

-#[derive(Clone, Debug)]
-struct PathBuildingHop<'a> {
+#[derive(Clone)]
+pub struct PathBuildingHop<'a> {


Dont think this needs to be pub, its only used internally in the routing.

TheBlueMatt · 2022-02-18T16:38:10Z

lightning/src/routing/router.rs

@@ -463,6 +463,13 @@ struct PathBuildingHop<'a> {
 	value_contribution_msat: u64,
 }

+impl<'a> core::fmt::Debug for PathBuildingHop<'a> {
+	fn fmt(&self, f: &mut core::fmt::Formatter) -> Result<(), core::fmt::Error> {
+        write!(f, "PathBuildingHop: node_id: {:?}, short_channel_id: {}, fee_msat: {}, path_penalty_msat: {}, path_htlc_minimum_msat: {}, cltv_expiry_delta: {}", self.node_id, self.candidate.short_channel_id(), self.fee_msat, self.path_penalty_msat, self.path_htlc_minimum_msat, self.candidate.cltv_expiry_delta())?;


Instead of fee_msat, maybe more informative to use next_hops_fee_msat, hop_use_fee_msat and total_fee_msat - {next_hops,hop_use]_fee_msat.

nit: tabs, not spaces, and maybe put a line break after the format string so the arguments are on the next line.

TheBlueMatt · 2022-02-18T16:59:58Z

I am somewhat dissatisfied with the current implementation because the print-out just doesn't seem very ergonomic. Ideally, we'll be able to have the print-out be something closer to what we have for logging routes.

Yea, I don't disagree, though I'm not sure how much its worth going the complexification route here, kinda up to you. This is much better than it was already.

There is an opportunity for improvement here by adding a macro to macro_logger that does a clean Display of PaymentPath, but that will mean having to exposing fields in PathBuildingHop and PaymentPath to be public, which I am not sure we want.

Yea, not a fan of that, if we want to improve the logging I think we should just add a util function in router.rs which does the printing given a list of PathBuildingHops, not do it via Debug or whatever.

jkczyz · 2022-02-18T21:19:26Z

lightning/src/routing/router.rs

@@ -463,6 +463,13 @@ struct PathBuildingHop<'a> {
 	value_contribution_msat: u64,
 }

+impl<'a> core::fmt::Debug for PathBuildingHop<'a> {
+	fn fmt(&self, f: &mut core::fmt::Formatter) -> Result<(), core::fmt::Error> {
+        write!(f, "PathBuildingHop: node_id: {:?}, short_channel_id: {}, fee_msat: {}, path_penalty_msat: {}, path_htlc_minimum_msat: {}, cltv_expiry_delta: {}", self.node_id, self.candidate.short_channel_id(), self.fee_msat, self.path_penalty_msat, self.path_htlc_minimum_msat, self.candidate.cltv_expiry_delta())?;


You can use Formatter methods as shown here: https://doc.rust-lang.org/std/fmt/struct.DebugStruct.html#examples

That way pretty-printing is honored if the caller specifies it.

jurvis · 2022-02-23T06:51:28Z

@jkczyz @TheBlueMatt thanks for taking the time to review! I made some changes based on your feedback. I improved the print-out to be prettier, now it looks like that (thanks for that tip on debug_struct, Jeff!):

TRACE  [lightning::routing::router : lightning/src/routing/router.rs, 1318] Found a path back to us from the target with 2 hops contributing up to 100 msat: 
 [
    PathBuildingHop {
        node_id: NodeId(02531fe6068134503d2723133227c867ac8fa6c83c537e9a44c3c5bdbdcb1fe337),
        short_channel_id: 2,
        next_hops_fee_msat: 100,
        hop_use_fee_msat: 0,
        total_fee_msat - next_hops_fee_msat: 0,
        total_fee_msat - hop_use_fee_msat: 100,
        path_penalty_msat: 0,
        path_htlc_minimum_msat: 4294967295,
        cltv_expiry_delta: 83,
    },
    PathBuildingHop {
        node_id: NodeId(03462779ad4aad39514614751a71085f2f10e1c7a593e4e030efb5b8721ce55b0b),
        short_channel_id: 4,
        next_hops_fee_msat: 0,
        hop_use_fee_msat: 0,
        total_fee_msat - next_hops_fee_msat: 100,
        total_fee_msat - hop_use_fee_msat: 100,
        path_penalty_msat: 0,
        path_htlc_minimum_msat: 0,
        cltv_expiry_delta: 65,
    },
]

Matt: I'm not entirely sure what to explicitly name total_fee_msat - [next_hops, hop_use]_fee_msat, so I just left the variables there. Let me know if you have something else in mind.

TheBlueMatt · 2022-02-23T16:46:22Z

Matt: I'm not entirely sure what to explicitly name total_fee_msat - [next_hops, hop_use]_fee_msat, so I just left the variables there. Let me know if you have something else in mind.

Oh, I meant one print of total_fee_msat less both the next_hops and hop_use fees. Seems strange to duplicate it.

Otherwise LGTM.

jurvis · 2022-02-23T18:03:58Z

@TheBlueMatt oh 😆 I'll change it!

TheBlueMatt · 2022-02-23T21:30:23Z

Oops, sorry, no, I think we need all three - next_hops_fee_msat, hop_use_fee_msat and total_fee_msat - {next_hops,hop_use]_fee_msat.

Add other fields to log for PathBuildingHop Use DebugStruct to print PathBuildingHop Fix PathBuildingHop visibility Add more useful fee print-outs Remove Features<NodeContext> from hop print-out Remove logging fields we don’t need Add fields to log back to PathBuildingHop

jkczyz self-requested a review February 18, 2022 16:35

TheBlueMatt reviewed Feb 18, 2022

View reviewed changes

jkczyz reviewed Feb 18, 2022

View reviewed changes

jurvis force-pushed the jurvis/2022-02-log-router-penalty-data-4 branch from 8268719 to 1ce2b92 Compare February 23, 2022 18:13

jurvis marked this pull request as ready for review February 23, 2022 18:13

jurvis force-pushed the jurvis/2022-02-log-router-penalty-data-4 branch from 1ce2b92 to a3c2dfd Compare February 24, 2022 01:51

TheBlueMatt approved these changes Feb 24, 2022

View reviewed changes

jurvis requested a review from jkczyz February 24, 2022 16:39

jkczyz approved these changes Feb 24, 2022

View reviewed changes

TheBlueMatt merged commit 4b77ce1 into lightningdevkit:main Feb 24, 2022

jkczyz mentioned this pull request Mar 7, 2022

Log penalty info in route-success line #1233

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Implement custom debug for PathBuildingHop #1318

Implement custom debug for PathBuildingHop #1318

jurvis commented Feb 18, 2022

codecov-commenter commented Feb 18, 2022 •

edited

TheBlueMatt Feb 18, 2022

TheBlueMatt Feb 18, 2022

TheBlueMatt commented Feb 18, 2022

jkczyz Feb 18, 2022

jurvis commented Feb 23, 2022

TheBlueMatt commented Feb 23, 2022

jurvis commented Feb 23, 2022

TheBlueMatt commented Feb 23, 2022

Implement custom debug for PathBuildingHop #1318

Implement custom debug for PathBuildingHop #1318

Conversation

jurvis commented Feb 18, 2022

Demo

Some Questions

codecov-commenter commented Feb 18, 2022 • edited

Codecov Report

TheBlueMatt Feb 18, 2022

Choose a reason for hiding this comment

TheBlueMatt Feb 18, 2022

Choose a reason for hiding this comment

TheBlueMatt commented Feb 18, 2022

jkczyz Feb 18, 2022

Choose a reason for hiding this comment

jurvis commented Feb 23, 2022

TheBlueMatt commented Feb 23, 2022

jurvis commented Feb 23, 2022

TheBlueMatt commented Feb 23, 2022

codecov-commenter commented Feb 18, 2022 •

edited