14645: Adds individual ops time output

Arvados-DCO-1.1-Signed-off-by: Eric Biagiotti <ebiagiotti@veritasgenetics.com>

diff --git a/services/fuse/arvados_fuse/__init__.py b/services/fuse/arvados_fuse/__init__.py
index 7c078858cacb9267ec103506d53e3117c88c119c..1ca3a0dc16cd21c2e28dfe32b6ebeffc3933b5cb 100644 (file)
--- a/services/fuse/arvados_fuse/__init__.py
+++ b/services/fuse/arvados_fuse/__init__.py
@@ -413,14 +413,25 @@ class Operations(llfuse.Operations):
         # initializing to continue
         self.initlock.set()
 
-    def fuse_ops_total_time(self):
-        ops_sum = 0.0
+    def time_samples(self):
         metrics = self.fuse_time.collect()
-        for metric in metrics:
-            for sample in metric.samples:
-                if sample.name == 'arvmount_fuse_operations_seconds_sum':
-                    ops_sum += sample.value      
-        return ops_sum
+
+        # We should have one parent summary metric, and child summaries for each op
+        if len(metrics) != 1:
+            _logger.warning("arv-mount metrics: invalid number of prometheus Summary metrics")
+            return [] 
+        return metrics[0].samples
+
+    def time_sum_samples(self):
+        return [sample for sample in self.time_samples() if sample.name == 'arvmount_fuse_operations_seconds_sum']
+
+    def time_sum_value(self, opname):
+        for op_sum in self.time_sum_samples():
+            if op_sum.labels['op'] == opname:
+                return op_sum.value
+
+    def time_sum_value_func(self, opname):
+        return lambda: self.time_sum_value(opname)
 
     @destroy_time.time()
     @catch_exceptions

diff --git a/services/fuse/arvados_fuse/crunchstat.py b/services/fuse/arvados_fuse/crunchstat.py
index e856d839b83338a879395c877c7b039e2f2c04f9..a21ca31403bb42a0976801617809104905b71641 100644 (file)
--- a/services/fuse/arvados_fuse/crunchstat.py
+++ b/services/fuse/arvados_fuse/crunchstat.py
@@ -55,9 +55,12 @@ def statlogger(interval, keep, ops):
         Stat("write", ops.write_ops_counter.get), 
         Stat("read", ops.read_ops_counter.get)
     ])
-    fusetime = StatWriter("fuseopstime", interval, [
-        Stat("seconds", ops.fuse_ops_total_time)
-    ])
+    fusetimes = []
+    for sample in ops.time_sum_samples():   
+        cur_op = sample.labels['op']   
+        fusetimes.append(StatWriter("fuseopstime", interval, [
+            Stat(cur_op, ops.time_sum_value_func(cur_op))
+        ]))
     blk = StatWriter("blkio:0:0", interval, [
         Stat("write", ops.write_counter.get),
         Stat("read", ops.read_counter.get)
@@ -68,8 +71,9 @@ def statlogger(interval, keep, ops):
         calls.update()
         net.update()
         cache.update()
-        fuseops.update()
-        fusetime.update()
         blk.update()
+        fuseops.update()
+        for ftime in fusetimes:
+            ftime.update()