Merge pull request #1702 from riganti/metrics-fix-help

Fix mistakes in doccomments in DotvvmMetrics, optimize exponential buckets

src/Framework/Framework/Hosting/DotvvmMetrics.cs

@@ -41,38 +41,39 @@ public static class DotvvmMetrics
         public static readonly Counter<long> BindingsCompiled =
             Meter.CreateCounter<long>("binding_compiled_total", description: "Number of bindings that were compiled. It should reach a steady state shortly after startup.");
 
-        /// <summary> Labeled by route=RouteName and request_type=GET/POST </summary>
+        /// <summary> Labeled by route=RouteName and request_type=Navigate/SpaNavigate/Command/StaticCommand </summary>
         public static readonly Histogram<long> ViewModelSize =
-            Meter.CreateHistogram<long>("viewmodel_size_bytes", unit: "bytes", description: "Size of the viewmodel JSON in bytes.");
+            Meter.CreateHistogram<long>("viewmodel_size_bytes", unit: "bytes", description: "Size of the result viewmodel JSON in bytes.");
 
-        /// <summary> Labeled by route=RouteName and request_type=GET/POST </summary>
+        /// <summary> Labeled by route=RouteName and request_type=Navigate/SpaNavigate/Command/StaticCommand </summary>
         public static readonly Histogram<double> ViewModelStringificationTime =
             Meter.CreateHistogram<double>("viewmodel_stringification_seconds", unit: "seconds", description: "Time it took to stringify the resulting JSON view model.");
 
-        /// <summary> Labeled by route=RouteName and request_type=GET/POST </summary>
+        /// <summary> Labeled by route=RouteName and request_type=Navigate/SpaNavigate/Command/StaticCommand </summary>
         public static readonly Histogram<double> ViewModelSerializationTime =
             Meter.CreateHistogram<double>("viewmodel_serialization_seconds", unit: "seconds", description: "Time it took to serialize view model to JSON objects.");
 
-        /// <summary> Labeled by route=RouteName and lifecycle_type=TODO </summary>
+        /// <summary> Labeled by route=RouteName and lifecycle_type=PreInit/Init/Load/PreRender/PreRenderComplete </summary>
         public static readonly Histogram<double> LifecycleInvocationDuration =
-            Meter.CreateHistogram<double>("control_lifecycle_seconds", unit: "seconds", description: "Time it took to process a request on the specific route.");
+            Meter.CreateHistogram<double>("control_lifecycle_seconds", unit: "seconds", description: "Time it took to call the On{lifecycle_type} method on all controls (does not include Init/Load/PreRender on view models).");
 
-        /// <summary> Labeled by route=RouteName, dothtml_file=filepath, request_type=GET/POST </summary>
+        /// <summary> Labeled by route=RouteName, dothtml_file=filepath, request_type=Navigate/SpaNavigate/Command/StaticCommand </summary>
         public static readonly Histogram<double> RequestDuration =
             Meter.CreateHistogram<double>("request_duration_seconds", unit: "seconds", description: "Time it took to process a request on the specific route.");
 
-        /// <summary> Labeled by route=RouteName, dothtml_file=filepath, request_type=GET/POST </summary>
+        /// <summary> Labeled by route=RouteName, request_type=Navigate/SpaNavigate/Command/StaticCommand </summary>
         public static readonly Counter<long> RequestsRejected =
             Meter.CreateCounter<long>("request_rejected_total", description: "Number of requests rejected (for security reasons) on the specific route.");
 
         /// <summary> Labeled by command="method invoked", result=Ok/Exception/UnhandledException </summary>
         public static readonly Histogram<double> StaticCommandInvocationDuration =
-            Meter.CreateHistogram<double>("staticcommand_invocation_seconds", unit: "seconds", description: "Time it took to invoke the staticCommand method. Note that serialization overhead is not included, look at request_duration_seconds{request_type=\"staticCommand\"}.");
+            Meter.CreateHistogram<double>("!", unit: "seconds", description: "Time it took to invoke the staticCommand method. Note that serialization overhead is not included, look at dotvvm_request_duration_seconds{request_type=\"StaticCommand\"}.");
 
         /// <summary> Labeled by command={command: TheBinding()}, result=Ok/Exception/UnhandledException </summary>
         public static readonly Histogram<double> CommandInvocationDuration =
-            Meter.CreateHistogram<double>("command_invocation_seconds", unit: "seconds", description: "Time it took to invoke the command method. Note that this does not include any of the overhead which is quite heavy for commands. Look at request_duration_seconds{request_type=\"command\"}.");
+            Meter.CreateHistogram<double>("command_invocation_seconds", unit: "seconds", description: "Time it took to invoke the command method. Note that this does not include any of the overhead which is quite heavy for commands. Look at dotvvm_request_duration_seconds{request_type=\"Command\"}.");
 
+        /// <summary> Labeled by route=RouteName, request_type=Navigate/SpaNavigate/Command/StaticCommand </summary>
         public static readonly Histogram<long> ValidationErrorsReturned =
             Meter.CreateHistogram<long>("viewmodel_validation_errors_total", description: "Number of validation errors returned to the client.");
 
@@ -100,6 +101,7 @@ public static class DotvvmMetrics
             Meter.CreateCounter<long>("viewmodel_cache_loaded_bytes_total", "bytes", description: "Total number of bytes loaded from view model cache");
 
 
+        /// <summary> Returns the default recommended buckets for the histograms defined in this class. </summary>
         public static double[]? TryGetRecommendedBuckets(Instrument instrument)
         {
             if (instrument.Meter != Meter)
@@ -110,24 +112,24 @@ public static class DotvvmMetrics
 
             var secStart = 1.0 / 128.0; // about 10ms, so that 1second is a boundary
             if (instrument == ResourceServeDuration)
-                return ExponentialBuckets(secStart, 2, 0.5);
+                return ExponentialBuckets(secStart, 0.5);
 
             if (instrument == ResourceServeDuration)
-                return ExponentialBuckets(secStart, 2, 0.5);
+                return ExponentialBuckets(secStart, 0.5);
 
             if (instrument == ResourceServeDuration)
-                return ExponentialBuckets(secStart, 2, 1);
+                return ExponentialBuckets(secStart, 1);
 
             if (instrument == RequestDuration || instrument == CommandInvocationDuration || instrument == StaticCommandInvocationDuration)
-                return ExponentialBuckets(secStart, 2, 65);
+                return ExponentialBuckets(secStart, 65);
 
             if (instrument.Unit == "seconds")
-                return ExponentialBuckets(secStart, 2, 2.0);
+                return ExponentialBuckets(secStart, 2.0);
 
             if (instrument.Unit == "bytes")
-                return ExponentialBuckets(1024, 2, 130 * 1024 * 1024); // 1KB ... 128MB
+                return ExponentialBuckets(1024, 130 * 1024 * 1024); // 1KB ... 128MB
 
-            return ExponentialBuckets(secStart, 2, 10);
+            return ExponentialBuckets(secStart, 10);
         }
 
         // The Counter from metrics doesn't count anything when there isn't a listener.
@@ -141,12 +143,26 @@ internal class BareCounters
             public static long DotvvmPropertyInitialized = 0;
         }
 
-        internal static double[] ExponentialBuckets(double start, double factor, double end)
+        internal static int IntegerLog2(double value)
         {
-            return Enumerable.Range(0, 1000)
-                .Select(i => start * Math.Pow(factor, i))
-                .TakeWhile(b => b <= end)
-                .ToArray();
+            // float64 is stored as 1 sign bit, 11 exponent bits, 52 mantissa bits
+            // where the exponent is essentially the integer logarithm we want
+            var bits = BitConverter.DoubleToInt64Bits(value);
+            var exponent = (int)((bits >> 52) & 0x7FF);
+            // the exponent is a signed integer, stored as unsigned with 1023 bias
+            return exponent - 1023;
+        }
+
+        internal static double[] ExponentialBuckets(double start, double end)
+        {
+            var buckets = new double[IntegerLog2(end / start) + 1];
+            var bucket = start;
+            for (int i = 0; i < buckets.Length; i++)
+            {
+                buckets[i] = bucket;
+                bucket *= 2;
+            }
+            return buckets;
         }
 
         internal static KeyValuePair<string, object?> RouteLabel(this IDotvvmRequestContext context) =>

src/Tests/Runtime/MetricsTests.cs

@@ -0,0 +1,29 @@
+using System;
+using DotVVM.Framework.Hosting;
+using Microsoft.VisualStudio.TestTools.UnitTesting;
+
+namespace DotVVM.Framework.Tests.Runtime
+{
+    [TestClass]
+    public class MetricsTests
+    {
+        [TestMethod]
+        public void IntLog()
+        {
+            for (int i = 1; i < 100; i++)
+            {
+                var log = DotvvmMetrics.IntegerLog2(i);
+                var expectedLog = (int)Math.Log(i, 2);
+                Assert.AreEqual(expectedLog, log);
+            }
+        }
+
+        [TestMethod]
+        public void ExponentialBuckets()
+        {
+            XAssert.Equal(new double[] { 1, 2, 4, 8, 16, 32, 64 }, DotvvmMetrics.ExponentialBuckets(1, 64));
+            XAssert.Equal(new double[] { 0.0078125, 0.015625, 0.03125, 0.0625, 0.125, 0.25, 0.5, 1, 2, 4, 8, 16, 32, 64 }, DotvvmMetrics.TryGetRecommendedBuckets(DotvvmMetrics.RequestDuration));
+
+        }
+    }
+}