-
Notifications
You must be signed in to change notification settings - Fork 2.8k
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
Add metrics to TxPool #2321
Add metrics to TxPool #2321
Changes from 79 commits
eb5525c
260b745
c84204b
8c5a979
ddb424e
27fb0fd
09357db
088b918
76b1084
090ada8
bd8b64b
f205434
de98ec5
58cf08b
c897f8a
f184a61
b86efce
b8241a0
94f3d42
4166809
3b128b5
8817d1a
9bc707c
3badebd
aadc59f
87eed6d
fa60c9e
10e3407
0978160
3920e74
703a89d
b10178e
b41331b
ef13002
fecb95d
f5f97e9
5387bc9
2b4482a
e25e1dc
4f9e452
76532a9
84d4595
ad5d73f
853100d
37d4cdc
0fa3a39
fcab288
5c6c3f0
013ab50
fcb571f
ed18ad1
2297804
11a6cfe
c921a09
0785b2d
aa751cd
0f85f04
21ebbc9
523932d
2b5da1d
1b5c428
2fba5d2
f23b469
e67ae19
c043ed7
7d17f99
e0124b6
f12185f
be71c4b
9636887
a128622
395f491
eb3872f
bee9c6f
8da222a
5da05f0
7b3e465
d1f94b7
e92c30f
365807b
dc197d3
1e3810d
889b92d
e3f201d
9cee869
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -562,6 +562,7 @@ impl Command { | |
pool_limits, | ||
heavy_work: pool_heavy_work_config, | ||
service_channel_limits, | ||
metrics: metrics.is_enabled(Module::TxPool), | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. nit: We should probably rename There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. done: e3f201d There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The way we implemented it in the base PR is that:
This could be confusing at first, but my main motivation was to minimize the changes in all components. |
||
}, | ||
block_producer: ProducerConfig { | ||
coinbase_recipient, | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -1,24 +1,94 @@ | ||
use crate::global_registry; | ||
use prometheus_client::metrics::histogram::Histogram; | ||
use crate::{ | ||
buckets::{ | ||
buckets, | ||
Buckets, | ||
}, | ||
global_registry, | ||
}; | ||
use prometheus_client::metrics::{ | ||
gauge::Gauge, | ||
histogram::Histogram, | ||
}; | ||
use std::sync::OnceLock; | ||
|
||
pub struct TxPoolMetrics { | ||
pub tx_size_histogram: Histogram, | ||
/// Size of transactions in the txpool in bytes | ||
pub tx_size: Histogram, | ||
pub number_of_transactions: Gauge, | ||
pub number_of_transactions_pending_verification: Gauge, | ||
pub number_of_executable_transactions: Gauge, | ||
/// Time of transactions in the txpool in seconds | ||
MitchTurner marked this conversation as resolved.
Show resolved
Hide resolved
|
||
pub transaction_time_in_txpool_secs: Histogram, | ||
/// Time actively spent by transaction insertion in the thread pool | ||
pub transaction_insertion_time_in_thread_pool_milliseconds: Histogram, | ||
/// How long it took for the selection algorithm to select transactions | ||
pub select_transaction_time_nanoseconds: Histogram, | ||
} | ||
Comment on lines
+24
to
+28
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think it is better to use the same units to track things. Like either nanoseconds, or milliseconds, or seconds. Not all 3=D I think Nanoseconds are ok, we always can divide it=) There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I'm ok with having different units in the metric producer (I mean: units that fit the value being observed best), as long as the unit is clearly communicated in the metric name. The presentation layer could do all necessary shenanigans required to show proper data. Otoh, there's also a merit in having a consistent time unit, but nanoseconds everywhere are too fine-grained in my opinion. For example, if transactions can live up to 10 minutes in the TxPool we're gonna be dealing with numbers such as I'll wait for more opinions before I start fiddling with the code. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I don't have a strong opinion on whether we decide to stick with nanoseconds for all metrics, as @rafal-ch said it has the merit of bringing uniformity across metrics. But even in that case we will need multiple timing buckets for different granularities. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. As per the meeting: we don't aim for a single unit for all metrics at the moment. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Changes in 49a79b2 |
||
|
||
impl Default for TxPoolMetrics { | ||
fn default() -> Self { | ||
let tx_sizes = Vec::new(); | ||
let tx_size = Histogram::new(buckets(Buckets::TransactionSize)); | ||
let transaction_time_in_txpool_secs = Histogram::new(buckets(Buckets::Timing)); | ||
let select_transaction_time_nanoseconds = | ||
Histogram::new(buckets(Buckets::Timing)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think we need to rename it to be There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Done in 7c79307 |
||
let transaction_insertion_time_in_thread_pool_milliseconds = | ||
rafal-ch marked this conversation as resolved.
Show resolved
Hide resolved
|
||
Histogram::new(buckets(Buckets::Timing)); | ||
|
||
let tx_size_histogram = Histogram::new(tx_sizes.into_iter()); | ||
let number_of_transactions = Gauge::default(); | ||
let number_of_transactions_pending_verification = Gauge::default(); | ||
let number_of_executable_transactions = Gauge::default(); | ||
|
||
let metrics = TxPoolMetrics { tx_size_histogram }; | ||
let metrics = TxPoolMetrics { | ||
tx_size, | ||
number_of_transactions, | ||
number_of_transactions_pending_verification, | ||
number_of_executable_transactions, | ||
transaction_time_in_txpool_secs, | ||
transaction_insertion_time_in_thread_pool_milliseconds, | ||
select_transaction_time_nanoseconds, | ||
}; | ||
|
||
let mut registry = global_registry().registry.lock(); | ||
registry.register( | ||
"Tx_Size_Histogram", | ||
"A Histogram keeping track of the size of txs", | ||
metrics.tx_size_histogram.clone(), | ||
"txpool_tx_size", | ||
"The size of transactions in the txpool", | ||
metrics.tx_size.clone(), | ||
); | ||
|
||
registry.register( | ||
"txpool_tx_time_in_txpool_seconds", | ||
"The time spent by a transaction in the txpool in seconds", | ||
metrics.transaction_time_in_txpool_secs.clone(), | ||
); | ||
|
||
registry.register( | ||
"txpool_number_of_transactions", | ||
"The number of transactions in the txpool", | ||
metrics.number_of_transactions.clone(), | ||
); | ||
|
||
registry.register( | ||
"txpool_number_of_executable_transactions", | ||
"The number of executable transactions in the txpool", | ||
metrics.number_of_executable_transactions.clone(), | ||
); | ||
|
||
registry.register( | ||
"txpool_number_of_transactions_pending_verification", | ||
"The number of transactions pending verification before entering the txpool", | ||
metrics.number_of_transactions_pending_verification.clone(), | ||
); | ||
|
||
registry.register( | ||
"txpool_select_transaction_time_nanoseconds", | ||
"The time it took to select transactions for inclusion in a block in nanoseconds", | ||
metrics.select_transaction_time_nanoseconds.clone(), | ||
); | ||
|
||
registry.register( | ||
"txpool_insert_transaction_time_milliseconds", | ||
"The time it took to insert a transaction in the txpool in milliseconds", | ||
metrics.select_transaction_time_nanoseconds.clone(), | ||
); | ||
|
||
metrics | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -3,7 +3,10 @@ mod collisions; | |
use std::{ | ||
collections::HashMap, | ||
iter, | ||
time::SystemTime, | ||
time::{ | ||
Instant, | ||
SystemTime, | ||
}, | ||
}; | ||
|
||
use collisions::CollisionsExt; | ||
|
@@ -228,6 +231,22 @@ where | |
Ok(can_store_transaction) | ||
} | ||
|
||
fn record_transaction_time_in_txpool(tx: &StorageData) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Also, we need to remember to record these metrics only if There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This is done in ed18ad1, although the workflow could be improved. Maybe having There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I don't mind the current flow. You're talking about here? best_txs
.into_iter()
.inspect(|storage_data| {
if metrics {
Self::record_transaction_time_in_txpool(storage_data)
}
}) It's pretty easy to read. |
||
if let Ok(elapsed) = tx.creation_instant.elapsed() { | ||
fuel_core_metrics::txpool_metrics::txpool_metrics() | ||
.transaction_time_in_txpool_secs | ||
.observe(elapsed.as_secs_f64()); | ||
Comment on lines
+236
to
+238
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This bucket has been updated in d46468c |
||
} else { | ||
tracing::warn!("Failed to calculate transaction time in txpool"); | ||
} | ||
} | ||
|
||
fn record_select_transaction_time_in_nanoseconds(start: Instant) { | ||
let elapsed = start.elapsed().as_nanos() as f64; | ||
fuel_core_metrics::txpool_metrics::txpool_metrics() | ||
.select_transaction_time_nanoseconds | ||
.observe(elapsed); | ||
} | ||
// TODO: Use block space also (https://github.com/FuelLabs/fuel-core/issues/2133) | ||
/// Extract transactions for a block. | ||
/// Returns a list of transactions that were selected for the block | ||
|
@@ -236,9 +255,23 @@ where | |
&mut self, | ||
constraints: Constraints, | ||
) -> Vec<ArcPoolTx> { | ||
self.selection_algorithm | ||
.gather_best_txs(constraints, &mut self.storage) | ||
let start = std::time::Instant::now(); | ||
let metrics = self.config.metrics; | ||
Comment on lines
+258
to
+259
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. let start = if self.config.metrics {
Some(std::time::Instant::now())
} else {
None
}; There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Updated in da77cf9 |
||
let best_txs = self | ||
.selection_algorithm | ||
.gather_best_txs(constraints, &mut self.storage); | ||
|
||
if metrics { | ||
Self::record_select_transaction_time_in_nanoseconds(start) | ||
}; | ||
Comment on lines
+264
to
+266
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. if let Some(start) = start {
Self::record_select_transaction_time_in_nanoseconds(start)
} There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Updated in da77cf9 |
||
|
||
best_txs | ||
.into_iter() | ||
.inspect(|storage_data| { | ||
if metrics { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. If you move this "If" before There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. |
||
Self::record_transaction_time_in_txpool(storage_data) | ||
} | ||
}) | ||
.map(|storage_entry| { | ||
self.update_components_and_caches_on_removal(iter::once(&storage_entry)); | ||
|
||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Is
Unchanged
the right designation here? It looks like we usedAdded
for the other metrics.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
yep, this was a mistake of mine (wanted to go to Changed, but I agree that added is better): chanlog updated in dc197d3
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
yep, Rafa pointed it out too. dc197d3