From 88b191dbbb6a98964458d1cfac22a764e405329d Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Marcel=20M=C3=A4rtens?= <marcel.cochem@googlemail.com>
Date: Fri, 26 Mar 2021 12:41:22 +0100
Subject: [PATCH] track state tick in a historgram too

---
 server/src/lib.rs         | 13 +++++--------
 server/src/metrics.rs     | 29 +++++++++++++++++++++++++++--
 server/src/sys/metrics.rs |  6 ++++++
 3 files changed, 38 insertions(+), 10 deletions(-)

diff --git a/server/src/lib.rs b/server/src/lib.rs
index e4ca587d56..c9fc9484a4 100644
--- a/server/src/lib.rs
+++ b/server/src/lib.rs
@@ -704,14 +704,11 @@ impl Server {
                 .set((before_persistence_updates - before_entity_cleanup).as_nanos() as i64);
             tt.with_label_values(&["persistence_updates"])
                 .set((end_of_server_tick - before_persistence_updates).as_nanos() as i64);
-        }
-
-        #[cfg(feature = "tracy")]
-        {
-            use common_base::tracy_client::{create_plot, Plot};
-            let entity_count = self.state.ecs().entities().join().count();
-            static ENTITY_COUNT: Plot = create_plot!("entity count");
-            ENTITY_COUNT.point(entity_count as f64);
+            tick_metrics.tick_time_hist.observe(
+                end_of_server_tick
+                    .duration_since(before_state_tick)
+                    .as_secs_f64(),
+            );
         }
 
         // 9) Finish the tick, pass control back to the frontend.
diff --git a/server/src/metrics.rs b/server/src/metrics.rs
index 8e9a0ffe0f..f8034d78d4 100644
--- a/server/src/metrics.rs
+++ b/server/src/metrics.rs
@@ -1,6 +1,6 @@
 use prometheus::{
-    Gauge, GaugeVec, HistogramOpts, HistogramVec, IntCounter, IntCounterVec, IntGauge, IntGaugeVec,
-    Opts, Registry,
+    Gauge, GaugeVec, Histogram, HistogramOpts, HistogramVec, IntCounter, IntCounterVec, IntGauge,
+    IntGaugeVec, Opts, Registry,
 };
 use std::{
     convert::TryInto,
@@ -48,6 +48,7 @@ pub struct TickMetrics {
     pub chunk_groups_count: IntGauge,
     pub entity_count: IntGauge,
     pub tick_time: IntGaugeVec,
+    pub tick_time_hist: Histogram,
     pub build_info: IntGauge,
     pub start_time: IntGauge,
     pub time_of_day: Gauge,
@@ -262,6 +263,28 @@ impl TickMetrics {
             Opts::new("tick_time", "time in ns required for a tick of the server"),
             &["period"],
         )?;
+        // 33.33ms is the ideal tick time. So we have hight detail around it.
+        // 300/700 are to detect high I/O blocks
+        let bucket = vec![
+            Duration::from_millis(8).as_secs_f64(),
+            Duration::from_millis(16).as_secs_f64(),
+            Duration::from_millis(24).as_secs_f64(),
+            Duration::from_millis(30).as_secs_f64(),
+            Duration::from_millis(33).as_secs_f64(),
+            Duration::from_millis(37).as_secs_f64(),
+            Duration::from_millis(45).as_secs_f64(),
+            Duration::from_millis(60).as_secs_f64(),
+            Duration::from_millis(100).as_secs_f64(),
+            Duration::from_millis(300).as_secs_f64(),
+            Duration::from_millis(700).as_secs_f64(),
+        ];
+        let tick_time_hist = Histogram::with_opts(
+            HistogramOpts::new(
+                "tick_time_hist",
+                "shows the detailed time in ns spend for the whole tick as histogram",
+            )
+            .buckets(bucket),
+        )?;
 
         let since_the_epoch = SystemTime::now()
             .duration_since(UNIX_EPOCH)
@@ -277,6 +300,7 @@ impl TickMetrics {
         registry.register(Box::new(time_of_day.clone()))?;
         registry.register(Box::new(light_count.clone()))?;
         registry.register(Box::new(tick_time.clone()))?;
+        registry.register(Box::new(tick_time_hist.clone()))?;
 
         Ok(Self {
             chonks_count,
@@ -284,6 +308,7 @@ impl TickMetrics {
             chunk_groups_count,
             entity_count,
             tick_time,
+            tick_time_hist,
             build_info,
             start_time,
             time_of_day,
diff --git a/server/src/sys/metrics.rs b/server/src/sys/metrics.rs
index e8c21c680b..7b348b88ee 100644
--- a/server/src/sys/metrics.rs
+++ b/server/src/sys/metrics.rs
@@ -102,6 +102,12 @@ impl<'a> System<'a> for Sys {
             if let Some(entities) = entities {
                 let entity_count = entities.join().count();
                 export_tick.entity_count.set(entity_count as i64);
+                #[cfg(feature = "tracy")]
+                {
+                    use common_base::tracy_client::{create_plot, Plot};
+                    static ENTITY_COUNT: Plot = create_plot!("entity count");
+                    ENTITY_COUNT.point(entity_count as f64);
+                }
             }
         }