sim-lib: Log payment summary every minute for more consistent results #141

carlaKC · 2023-10-17T16:15:10Z

Fixes #128.

Example of new, regular output:

2023-10-17T16:09:44.984Z INFO [sim_lib] Summary of results will be reported every 60s.
...
2023-10-17T16:10:44.986Z INFO [sim_lib] Processed 4 payments sending 19832 msat total with 100.00% success rate.
2023-10-17T16:11:44.991Z INFO [sim_lib] Processed 12 payments sending 275055 msat total with 83.33% success rate.
2023-10-17T16:12:44.994Z INFO [sim_lib] Processed 14 payments sending 278414 msat total with 78.57% success rate.
2023-10-17T16:13:44.996Z INFO [sim_lib] Processed 18 payments sending 3151487 msat total with 77.78% success rate.

sr-gi

LGTM.

As a side note, I think this approach makes more sense currently, given we are simulating in real-time. However, it is worth noting that if we add simulated time down the line, we may want to report based on:

time for real time
payment count for simulated time

sr-gi · 2023-10-23T19:21:21Z

sim-lib/src/lib.rs

+        tasks.spawn(run_results_logger(
+            listener.clone(),
+            result_logger.clone(),
+            Duration::from_secs(60),


We may want to make this configurable and default it to 1 min

Clippy starts getting angry if we have too many args for Simulation::new - pushed example in e929a2d which adds a SimulationConfig struct to house all of our various flags.

If we like it, I'll break that up into a refactor commit + add some validation on the config so that we fail if we're given bad config values (eg, zero expected amount).

Concept ACK on this. I think that's also a first step towards allowing reading conf options both from cmd and a config file. I don't think there's an idiomatic way of doing that, but here's an example of how I've dealt with that in the past: https://github.com/talaia-labs/rust-teos/blob/master/teos/src/config.rs

For context, StructOpt was just a wrapper around clap that made it nicer to use, but looks like the new version of the latter includes most (if not all) the functionality from the former

carlaKC · 2023-10-24T20:22:28Z

However, it is worth noting that if we add simulated time down the line, we may want to report based on
time for real time
payment count for simulated time

Yeah agree, would def need to make a change if we implement #81. We'll need to do a bunch of refactoring for that, so we can just trait out the logger as well.

okjodom · 2023-10-25T18:33:38Z

tACK e929a2d ✅

sr-gi

tACK with some comments.

sr-gi · 2023-10-26T15:11:58Z

sim-cli/src/main.rs

@@ -46,6 +48,9 @@ struct Cli {
    /// Do not create an output file containing the simulations results
    #[clap(long, default_value_t = false)]
    no_results: bool,
+    /// The interval at which to log payment summaries, expressed in seconds.
+    #[clap(long, default_value_t = 60)]


nit: I think we should define this as a constant, given all the other defaults are.

We can also take the chance to remove the line break between them :P

sr-gi · 2023-10-26T15:14:38Z

sim-cli/src/main.rs

@@ -1,7 +1,9 @@
 use bitcoin::secp256k1::PublicKey;
+use sim_lib::SimulationConfig;


Merge this with the others at L11

sr-gi · 2023-10-26T15:37:02Z

sim-lib/src/lib.rs

+    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
+        let total_payments = self.success_payment + self.failed_payment;
+        write!(
+            f,
+            "Processed {} payments sending {} msat total with {:.2}% success rate.",
+            total_payments,
+            self.total_sent,
+            (self.success_payment as f64 / total_payments as f64) * 100.0
+        )
+    }
+}


It could now be the case that we sample before a single payment has been tracked yet, meaning that we'd get 0/0 when reporting the success rate, yielding NaN:

INFO [sim_lib] Processed 0 payments sending 0 msat total with NaN% success rate.

We should treat that as a special case:

Suggested change

fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {

let total_payments = self.success_payment + self.failed_payment;

write!(

f,

"Processed {} payments sending {} msat total with {:.2}% success rate.",

total_payments,

self.total_sent,

(self.success_payment as f64 / total_payments as f64) * 100.0

)

}

}

fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {

let total_payments = self.success_payment + self.failed_payment;

let rate = self.success_payment as f64 / total_payments as f64;

if rate.is_nan() {

write!(

f,

"Processed {} payments sending {} msat total.",

total_payments, self.total_sent

)

} else {

write!(

f,

"Processed {} payments sending {} msat total with {:.2}% success rate.",

total_payments,

self.total_sent,

rate * 100.0

)

}

}

Rate is only NaN if we haven't sent anything yet, so the special case will just print "Processed 0 payments sending 0 msat total." IMO it's not worth the effort to convey essentially the same information in double the LOC, I think it's reasonably understandable as is.

We're going to need to start the report logger in its own task in the commit that follows (so that we can log every minute). This preparatory commit refactors creations of a PaymentResultLogger so that we can easily spin up its run task in our existing join set.

carlaKC · 2023-10-31T19:32:55Z

Dropped the config refactor off this - I'll do it in a follow up, want to close this one out in the meantime (sent simln to some people to play around with, nice to have it logging regularly for demo purposes).

sr-gi

tACK 71d44cb

It'd be good to open an issue to track the pending changes. At least so we don't forget to add an arg for the logging interval

sr-gi · 2023-11-03T18:50:09Z

sim-lib/src/lib.rs

@@ -967,18 +974,44 @@ impl PaymentResultLogger {
        }

        self.total_sent += details.amount_msat;
-        self.call_count += 1;


I just realized that this was a u8, which would have made the logger task panic after 255 additions, so that's patches 😆

carlaKC force-pushed the 128-regularlogging branch 2 times, most recently from 4bdeb6f to e2dfa5e Compare October 20, 2023 14:26

carlaKC marked this pull request as ready for review October 20, 2023 14:34

carlaKC requested review from okjodom and sr-gi October 20, 2023 14:34

sr-gi reviewed Oct 23, 2023

View reviewed changes

carlaKC mentioned this pull request Oct 23, 2023

sim-all: Allow running the simulator without it writing on disk #146

Merged

carlaKC force-pushed the 128-regularlogging branch from e2dfa5e to f097084 Compare October 24, 2023 20:22

okjodom approved these changes Oct 25, 2023

View reviewed changes

sr-gi reviewed Oct 26, 2023

View reviewed changes

carlaKC added 2 commits October 31, 2023 15:27

sim-lib: report results on time interval for more consistent logging

71d44cb

carlaKC force-pushed the 128-regularlogging branch from e929a2d to 71d44cb Compare October 31, 2023 19:30

carlaKC requested a review from sr-gi November 3, 2023 18:34

sr-gi approved these changes Nov 3, 2023

View reviewed changes

carlaKC mentioned this pull request Nov 6, 2023

Refactor: Create config struct for simulator #157

Open

carlaKC merged commit 3416e02 into bitcoin-dev-project:main Nov 6, 2023
2 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

sim-lib: Log payment summary every minute for more consistent results #141

sim-lib: Log payment summary every minute for more consistent results #141

carlaKC commented Oct 17, 2023

sr-gi left a comment

sr-gi Oct 23, 2023

carlaKC Oct 24, 2023

sr-gi Oct 24, 2023

carlaKC commented Oct 24, 2023

okjodom commented Oct 25, 2023

sr-gi left a comment

sr-gi Oct 26, 2023

sr-gi Oct 26, 2023

sr-gi Oct 26, 2023

carlaKC Oct 31, 2023

carlaKC commented Oct 31, 2023

sr-gi left a comment

sr-gi Nov 3, 2023

carlaKC Nov 6, 2023

		@@ -1,7 +1,9 @@
		use bitcoin::secp256k1::PublicKey;
		use sim_lib::SimulationConfig;

sim-lib: Log payment summary every minute for more consistent results #141

sim-lib: Log payment summary every minute for more consistent results #141

Conversation

carlaKC commented Oct 17, 2023

sr-gi left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

carlaKC commented Oct 24, 2023

okjodom commented Oct 25, 2023

sr-gi left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

carlaKC commented Oct 31, 2023

sr-gi left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment