Merge pull request #968 from skhoroshavin/gc-metrics

Add GC-related metrics
hyperledger · Nov 8, 2018 · 7ddbeb3 · 7ddbeb3
2 parents 49dc4b7 + bdd0fa5
commit 7ddbeb3
Show file tree

Hide file tree

Showing 2 changed files with 33 additions and 5 deletions.
diff --git a/plenum/common/metrics_collector.py b/plenum/common/metrics_collector.py
@@ -68,6 +68,10 @@ class MetricsName(IntEnum):
     NODE_RSS_SIZE = 51
     NODE_VMS_SIZE = 52
     CONNECTED_CLIENTS_NUM = 53
+    GC_TRACKED_OBJECTS = 54
+    GC_GEN0_TIME = 55
+    GC_GEN1_TIME = 56
+    GC_GEN2_TIME = 57
 
     # Node service statistics
     NODE_PROD_TIME = 100

diff --git a/plenum/server/node.py b/plenum/server/node.py
@@ -5,18 +5,17 @@
 from collections import deque
 from contextlib import closing
 from functools import partial
-from statistics import mean
 from typing import Dict, Any, Mapping, Iterable, List, Optional, Set, Tuple, Callable
 
+import gc
 import psutil
-import sys
 from intervaltree import IntervalTree
 
 from common.exceptions import LogicError
 from common.serializers.serialization import state_roots_serializer
 from crypto.bls.bls_key_manager import LoadBLSKeyError
 from plenum.common.metrics_collector import KvStoreMetricsCollector, NullMetricsCollector, MetricsName, \
-    async_measure_time, measure_time
+    async_measure_time, measure_time, MetricsCollector
 from plenum.server.backup_instance_faulty_processor import BackupInstanceFaultyProcessor
 from plenum.server.inconsistency_watchers import NetworkInconsistencyWatcher
 from plenum.server.quota_control import QuotaControl, StaticQuotaControl, RequestQueueQuotaControl
@@ -121,6 +120,25 @@
 logger = getlogger()
 
 
+class GcTimeTracker:
+    def __init__(self, metrics: MetricsCollector):
+        self._metrics = metrics
+        self._timestamps = {}
+        gc.callbacks.append(self._gc_callback)
+
+    def _gc_callback(self, action, info):
+        gen = info['generation']
+        if action == 'start':
+            self._timestamps[gen] = time.perf_counter()
+        else:
+            start = self._timestamps.get(gen)
+            if start is None:
+                return
+            elapsed = time.perf_counter() - start
+            self._metrics.add_event(MetricsName.GC_GEN0_TIME + gen, elapsed)
+            self._timestamps[gen] = None
+
+
 class Node(HasActionQueue, Motor, Propagator, MessageProcessor, HasFileStorage,
            HasPoolManager, PluginLoaderHelper, MessageReqProcessor, HookManager):
     """
@@ -193,6 +211,8 @@ def __init__(self,
         self.requestExecuter = {}   # type: Dict[int, Callable]
 
         self.metrics = self._createMetricsCollector()
+        if self.config.METRICS_COLLECTOR_TYPE is not None:
+            self._gc_time_tracker = GcTimeTracker(self.metrics)
 
         Motor.__init__(self)
 
@@ -2592,11 +2612,17 @@ def _update_new_ordered_reqs_count(self):
             return False
 
     def flush_metrics(self):
+        # Flush accumulated should always be done to avoid numeric overflow in accumulators
+        self.metrics.flush_accumulated()
+        if self.config.METRICS_COLLECTOR_TYPE is None:
+            return
+
         ram_by_process = psutil.Process().memory_info()
         self.metrics.add_event(MetricsName.AVAILABLE_RAM_SIZE, psutil.virtual_memory().available)
         self.metrics.add_event(MetricsName.NODE_RSS_SIZE, ram_by_process.rss)
         self.metrics.add_event(MetricsName.NODE_VMS_SIZE, ram_by_process.vms)
         self.metrics.add_event(MetricsName.CONNECTED_CLIENTS_NUM, self.clientstack.connected_clients_num)
+        self.metrics.add_event(MetricsName.GC_TRACKED_OBJECTS, len(gc.get_objects()))
 
         self.metrics.add_event(MetricsName.REQUEST_QUEUE_SIZE, len(self.requests))
         self.metrics.add_event(MetricsName.FINALISED_REQUEST_QUEUE_SIZE, self.requests.finalised_count)
@@ -2768,8 +2794,6 @@ def store_rocksdb_metrics(name, storage):
         if self.config.METRICS_COLLECTOR_TYPE == 'kv':
             store_rocksdb_metrics(MetricsName.STORAGE_METRICS_READERS, self.metrics._storage)
 
-        self.metrics.flush_accumulated()
-
     @measure_time(MetricsName.NODE_CHECK_PERFORMANCE_TIME)
     def checkPerformance(self) -> Optional[bool]:
         """