Fix PohRecorder Metrics (#6644)

* Update Poh Recorder Dashboard

* Update PohRecorder logging
This commit is contained in:
carllin 2019-10-30 18:55:29 -07:00 committed by GitHub
parent 6454bfe754
commit 59f3dc3b6b
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 65 additions and 19 deletions

View File

@ -313,7 +313,7 @@ impl PohRecorder {
let poh_entry = self.poh.lock().unwrap().tick(); let poh_entry = self.poh.lock().unwrap().tick();
inc_new_counter_warn!( inc_new_counter_warn!(
"poh_recorder-tick_lock_contention", "poh_recorder-tick_lock_contention",
timing::duration_as_ms(&now.elapsed()) as usize timing::duration_as_us(&now.elapsed()) as usize
); );
let now = Instant::now(); let now = Instant::now();
if let Some(poh_entry) = poh_entry { if let Some(poh_entry) = poh_entry {
@ -323,7 +323,7 @@ impl PohRecorder {
if self.leader_first_tick_height.is_none() { if self.leader_first_tick_height.is_none() {
inc_new_counter_warn!( inc_new_counter_warn!(
"poh_recorder-tick_overhead", "poh_recorder-tick_overhead",
timing::duration_as_ms(&now.elapsed()) as usize timing::duration_as_us(&now.elapsed()) as usize
); );
return; return;
} }
@ -339,7 +339,7 @@ impl PohRecorder {
} }
inc_new_counter_warn!( inc_new_counter_warn!(
"poh_recorder-tick_overhead", "poh_recorder-tick_overhead",
timing::duration_as_ms(&now.elapsed()) as usize timing::duration_as_us(&now.elapsed()) as usize
); );
} }
@ -363,20 +363,29 @@ impl PohRecorder {
return Err(Error::PohRecorderError(PohRecorderError::MaxHeightReached)); return Err(Error::PohRecorderError(PohRecorderError::MaxHeightReached));
} }
let now = Instant::now(); {
if let Some(poh_entry) = self.poh.lock().unwrap().record(mixin) { let now = Instant::now();
let mut poh_lock = self.poh.lock().unwrap();
inc_new_counter_warn!( inc_new_counter_warn!(
"poh_recorder-record_lock_contention", "poh_recorder-record_lock_contention",
timing::duration_as_ms(&now.elapsed()) as usize timing::duration_as_us(&now.elapsed()) as usize
); );
let entry = Entry { let now = Instant::now();
num_hashes: poh_entry.num_hashes, let res = poh_lock.record(mixin);
hash: poh_entry.hash, inc_new_counter_warn!(
transactions, "poh_recorder-record_ms",
}; timing::duration_as_us(&now.elapsed()) as usize
self.sender );
.send((working_bank.bank.clone(), (entry, self.tick_height)))?; if let Some(poh_entry) = res {
return Ok(()); let entry = Entry {
num_hashes: poh_entry.num_hashes,
hash: poh_entry.hash,
transactions,
};
self.sender
.send((working_bank.bank.clone(), (entry, self.tick_height)))?;
return Ok(());
}
} }
// record() might fail if the next PoH hash needs to be a tick. But that's ok, tick() // record() might fail if the next PoH hash needs to be a tick. But that's ok, tick()
// and re-record() // and re-record()

View File

@ -6335,7 +6335,7 @@
"x": 8, "x": 8,
"y": 68 "y": 68
}, },
"id": 46, "id": 47,
"legend": { "legend": {
"alignAsTable": false, "alignAsTable": false,
"avg": false, "avg": false,
@ -6376,7 +6376,7 @@
], ],
"orderByTime": "ASC", "orderByTime": "ASC",
"policy": "default", "policy": "default",
"query": "SELECT sum(\"count\") FROM \"$testnet\".\"autogen\".\"poh_recorder-tick_lock_contention\" WHERE host_id::tag =~ /$hostid/ AND $timeFilter GROUP BY time($__interval)", "query": "SELECT mean(\"count\") FROM \"$testnet\".\"autogen\".\"poh_recorder-tick_lock_contention\" WHERE host_id::tag =~ /$hostid/ AND $timeFilter GROUP BY time($__interval)",
"rawQuery": true, "rawQuery": true,
"refId": "F", "refId": "F",
"resultFormat": "time_series", "resultFormat": "time_series",
@ -6413,7 +6413,7 @@
], ],
"orderByTime": "ASC", "orderByTime": "ASC",
"policy": "default", "policy": "default",
"query": "SELECT sum(\"count\") FROM \"$testnet\".\"autogen\".\"poh_recorder-record_lock_contention\" WHERE host_id::tag =~ /$hostid/ AND $timeFilter GROUP BY time($__interval)", "query": "SELECT mean(\"count\") FROM \"$testnet\".\"autogen\".\"poh_recorder-record_lock_contention\" WHERE host_id::tag =~ /$hostid/ AND $timeFilter GROUP BY time($__interval)",
"rawQuery": true, "rawQuery": true,
"refId": "A", "refId": "A",
"resultFormat": "time_series", "resultFormat": "time_series",
@ -6450,7 +6450,7 @@
], ],
"orderByTime": "ASC", "orderByTime": "ASC",
"policy": "default", "policy": "default",
"query": "SELECT sum(\"count\") FROM \"$testnet\".\"autogen\".\"poh_recorder-tick_overhead\" WHERE host_id::tag =~ /$hostid/ AND $timeFilter GROUP BY time($__interval)", "query": "SELECT mean(\"count\") FROM \"$testnet\".\"autogen\".\"poh_recorder-tick_overhead\" WHERE host_id::tag =~ /$hostid/ AND $timeFilter GROUP BY time($__interval)",
"rawQuery": true, "rawQuery": true,
"refId": "B", "refId": "B",
"resultFormat": "time_series", "resultFormat": "time_series",
@ -6469,6 +6469,43 @@
] ]
], ],
"tags": [] "tags": []
},
{
"groupBy": [
{
"params": [
"$__interval"
],
"type": "time"
},
{
"params": [
"null"
],
"type": "fill"
}
],
"orderByTime": "ASC",
"policy": "default",
"query": "SELECT mean(\"count\") FROM \"$testnet\".\"autogen\".\"poh_recorder-record_ms\" WHERE host_id::tag =~ /$hostid/ AND $timeFilter GROUP BY time($__interval)",
"rawQuery": true,
"refId": "C",
"resultFormat": "time_series",
"select": [
[
{
"params": [
"value"
],
"type": "field"
},
{
"params": [],
"type": "mean"
}
]
],
"tags": []
} }
], ],
"thresholds": [], "thresholds": [],
@ -6490,7 +6527,7 @@
}, },
"yaxes": [ "yaxes": [
{ {
"format": "ms", "format": "µs",
"label": null, "label": null,
"logBase": 1, "logBase": 1,
"max": null, "max": null,