Logging Fixes (#151)

- Remove duplicate slot logic due to ancient version of
yellowstone-client-crate
- Remove info logging every 10 slots -- make it debug instead
- Only send metrics every 100 slots instead of 10 slots
- Add an `info` with stats every 1/10 of an epoch

Author: hash-envy

jito-bell/src/lib.rs

@@ -104,7 +104,11 @@ impl JitoBellHandler {
             match message {
                 Ok(msg) => match msg.update_oneof {
                     Some(UpdateOneof::Slot(update_slot)) => {
-                        self.handle_slot_update(update_slot.slot);
+                        // Newer geyser servers leak interslot SlotStatuses that v2.0.0 protos
+                        // decode with garbage status; dedupe by accepting only our commitment.
+                        if update_slot.status == self.subscribe_option.commitment as i32 {
+                            self.handle_slot_update(update_slot.slot);
+                        }
                     }
                     Some(UpdateOneof::Transaction(transaction)) => {
                         // A parser is a list of instructions + events from the transaction that
@@ -186,6 +190,7 @@ impl JitoBellHandler {
         let current_epoch = slot / DEFAULT_SLOTS_PER_EPOCH;
         self.epoch_metrics.update_slot(slot);
         self.epoch_metrics.emit_slot_heartbeat(slot);
+        self.epoch_metrics.emit_epoch_progress(slot);
         if current_epoch != self.epoch_metrics.epoch {
             datapoint_info!(
                 "jito-bell-epoch",

jito-bell/src/metrics.rs

@@ -1,4 +1,6 @@
-use solana_metrics::datapoint_info;
+use log::info;
+use solana_metrics::{datapoint::DataPoint, datapoint_info, submit};
+use solana_sdk::clock::DEFAULT_SLOTS_PER_EPOCH;
 
 #[derive(Debug, Default)]
 pub(crate) struct NotificationMetrics {
@@ -63,16 +65,36 @@ impl EpochMetrics {
         datapoint_info!(name, ("count", count, i64), ("epoch", self.epoch, i64),);
     }
 
-    pub fn emit_slot_heartbeat(&self, slot: u64) {
-        if slot.is_multiple_of(10) {
-            datapoint_info!(
-                "jito-bell-slot-heartbeat",
-                ("slot", slot, i64),
-                ("epoch", self.epoch, i64),
+    pub fn emit_epoch_progress(&self, slot: u64) {
+        if slot.is_multiple_of(DEFAULT_SLOTS_PER_EPOCH / 10) {
+            let position = slot % DEFAULT_SLOTS_PER_EPOCH;
+            info!(
+                "epoch={} slot={} ({position}/{}) tx={} failed_tx={} notif_ok={} notif_fail={} squads_parsed={}",
+                self.epoch,
+                slot,
+                DEFAULT_SLOTS_PER_EPOCH,
+                self.tx,
+                self.failed_tx,
+                self.notification.success,
+                self.notification.fail,
+                self.squads.proposals_parsed,
             );
         }
     }
 
+    pub fn emit_slot_heartbeat(&self, slot: u64) {
+        if slot.is_multiple_of(100) {
+            // Manual datapoint construction (vs. datapoint_info!): we want the point
+            // submitted to InfluxDB unconditionally, with only the agent's per-point
+            // log line filtered out by RUST_LOG. datapoint_debug! would gate the
+            // submit on log_enabled!(Debug), dropping the metric at default verbosity.
+            let mut point = DataPoint::new("jito-bell-slot-heartbeat");
+            point.add_field_i64("slot", slot as i64);
+            point.add_field_i64("epoch", self.epoch as i64);
+            submit(point, log::Level::Debug);
+        }
+    }
+
     pub fn increment_tx_count(&mut self) {
         self.tx += 1;
         self.emit_live_metric("jito-bell-transactions", 1);