Skip to content

Improve router logging and update documentation #2436

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

Merged
merged 2 commits into from
Jul 21, 2023

Conversation

tnull
Copy link
Contributor

@tnull tnull commented Jul 21, 2023

Fixes #1646

As #2417 will slip to a future release, this PR just includes the improved logging and documentation fixups of of our router.

Previously, we barely gave any hints why we excluded certain hops during pathfinding. Here, we introduce more verbose logging by a) accounting how much candidates we ignored for which reasons and b) logging any first/last/blinded hops we end up ignoring.

We also improve documentation as RouteParameters are not included in Event::PaymentPathFailed since 0.0.115, and we don't give value/payee as immediate arguments to find_route anymore.

@tnull
Copy link
Contributor Author

tnull commented Jul 21, 2023

Just to carry over some of the context here, the benches from #2417 with n = 10000 (on Linux on Intel(R) Xeon(R) CPU E3-1226 v3 @ 3.30GHz) interestingly indicate the logging changes actually maintain or even improve the pathfinding performance:

Benchmarking generate_routes_with_zero_penalty_scorer: Collecting 10000 samples in estimated 1208.3 s (10k iterations)
Benchmarking generate_routes_with_zero_penalty_scorer: Analyzing
generate_routes_with_zero_penalty_scorer
                        time:   [118.83 ms 119.77 ms 120.71 ms]
                        change: [-1.7780% -0.4836% +0.7940%] (p = 0.45 > 0.05)
                        No change in performance detected.
Found 400 outliers among 10000 measurements (4.00%)
  400 (4.00%) high mild

Benchmarking generate_mpp_routes_with_zero_penalty_scorer: Collecting 10000 samples in estimated 1139.0 s (10k iterations)
Benchmarking generate_mpp_routes_with_zero_penalty_scorer: Analyzing
generate_mpp_routes_with_zero_penalty_scorer
                        time:   [110.90 ms 111.74 ms 112.58 ms]
                        change: [-11.985% -10.971% -9.9144%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 400 outliers among 10000 measurements (4.00%)
  400 (4.00%) high mild

Benchmarking generate_routes_with_probabilistic_scorer: Collecting 10000 samples in estimated 1587.6 s (10k iterations)
Benchmarking generate_routes_with_probabilistic_scorer: Analyzing
generate_routes_with_probabilistic_scorer
                        time:   [158.24 ms 158.62 ms 159.00 ms]
                        change: [-2.6897% -2.4127% -2.1132%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 183 outliers among 10000 measurements (1.83%)
  183 (1.83%) low mild

Benchmarking generate_mpp_routes_with_probabilistic_scorer: Collecting 10000 samples in estimated 1552.4 s (10k iterations)
Benchmarking generate_mpp_routes_with_probabilistic_scorer: Analyzing
generate_mpp_routes_with_probabilistic_scorer
                        time:   [156.10 ms 156.53 ms 156.96 ms]
                        change: [-1.8478% -1.4928% -1.1282%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 200 outliers among 10000 measurements (2.00%)
  200 (2.00%) high mild

Benchmarking generate_large_mpp_routes_with_probabilistic_scorer: Collecting 10000 samples in estimated 3672.8 s (10k iterations)
Benchmarking generate_large_mpp_routes_with_probabilistic_scorer: Analyzing
generate_large_mpp_routes_with_probabilistic_scorer
                        time:   [349.39 ms 354.79 ms 360.26 ms]
                        change: [-15.815% -14.168% -12.477%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 1400 outliers among 10000 measurements (14.00%)
  802 (8.02%) high mild
  598 (5.98%) high severe

@codecov-commenter
Copy link

codecov-commenter commented Jul 21, 2023

Codecov Report

Patch coverage: 100.00% and project coverage change: +0.71 🎉

Comparison is base (e4c44f3) 90.24% compared to head (14f5544) 90.96%.

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

❗ Your organization is not using the GitHub App Integration. As a result you may experience degraded service beginning May 15th. Please install the Github App Integration for your organization. Read more.

Additional details and impacted files
@@            Coverage Diff             @@
##             main    #2436      +/-   ##
==========================================
+ Coverage   90.24%   90.96%   +0.71%     
==========================================
  Files         106      106              
  Lines       55774    62618    +6844     
  Branches    55774    62618    +6844     
==========================================
+ Hits        50335    56959    +6624     
- Misses       5439     5659     +220     
Impacted Files Coverage Δ
lightning/src/routing/router.rs 93.51% <100.00%> (+0.16%) ⬆️

... and 10 files with indirect coverage changes

☔ View full report in Codecov by Sentry.
📢 Do you have feedback about the report comment? Let us know in this issue.

Comment on lines 1721 to 1761
if !contributes_sufficient_value || exceeds_max_path_length ||
exceeds_cltv_delta_limit || payment_failed_on_this_channel {
// Path isn't useful, ignore it and move on.
if !contributes_sufficient_value {
if should_log_candidate {
log_trace!(logger, "Ignoring {} due to insufficient value contribution.", LoggedCandidateHop(&$candidate));
}
num_ignored_value_contribution += 1;
} else if exceeds_max_path_length {
if should_log_candidate {
log_trace!(logger, "Ignoring {} due to exceeding max. path length limit.", LoggedCandidateHop(&$candidate));
}
num_ignored_path_length_limit += 1;
} else if exceeds_cltv_delta_limit {
if should_log_candidate {
log_trace!(logger, "Ignoring {} due to exceeding CLTV delta limit.", LoggedCandidateHop(&$candidate));
}
num_ignored_cltv_delta_limit += 1;
} else if payment_failed_on_this_channel {
if should_log_candidate {
log_trace!(logger, "Ignoring {} due to a failed previous payment attempt.", LoggedCandidateHop(&$candidate));
}
num_ignored_previously_failed += 1;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are these actually mutually exclusive?

Copy link
Contributor

@valentinewallace valentinewallace Jul 21, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

True, might be best to just have one long log that includes all the variables, which would remove all the branching as well

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are these actually mutually exclusive?

Not necessarily, but we log and count the first reason why a candidate would be excluded. Yes, some should count towards multiple categories, but it's probably not worth to check for all combinations.

True, might be best to just have one long log that includes all the variables

Mh, I think even if some candidates might fall under multiple categories, it's much more readable to have individual logs?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think its useful to have individual reasons why a particular candidate was ignored.

Copy link
Contributor

@jkczyz jkczyz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. Please squash

tnull added 2 commits July 21, 2023 20:28
As `RouteParameters` are not included anymore in
`Event::PaymentPathFailed` since 0.0.115, and we don't give value/payee
as immediate arguments to `find_route` anymore.
Previously, we barely gave any hints why we excluded certain hops during
pathfinding. Here, we introduce more verbose logging by a) accounting
how much candidates we ignored for which reasons and b) logging any
first/last/blinded hops we end up ignoring.

Fixes lightningdevkit#1646.
@tnull tnull force-pushed the 2023-07-improve-router-logging branch from fd94350 to 1db53a9 Compare July 21, 2023 18:28
@tnull
Copy link
Contributor Author

tnull commented Jul 21, 2023

LGTM. Please squash

Squashed without further changes.

@jkczyz jkczyz merged commit 0fadb54 into lightningdevkit:main Jul 21, 2023
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

Successfully merging this pull request may close these issues.

Improve logging of pathfinding behavior
6 participants