From 9b8d4177f91cb1d127057e251ffa97a07ebbd388 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Standa=20Luke=C5=A1?= Date: Wed, 27 Sep 2023 13:19:23 +0200 Subject: [PATCH 1/2] Fix mistakes in doccomments in DotvvmMetrics --- .../Framework/Hosting/DotvvmMetrics.cs | 22 ++++++++++--------- 1 file changed, 12 insertions(+), 10 deletions(-) diff --git a/src/Framework/Framework/Hosting/DotvvmMetrics.cs b/src/Framework/Framework/Hosting/DotvvmMetrics.cs index fd658108de..918edb5f9d 100644 --- a/src/Framework/Framework/Hosting/DotvvmMetrics.cs +++ b/src/Framework/Framework/Hosting/DotvvmMetrics.cs @@ -41,38 +41,39 @@ public static class DotvvmMetrics public static readonly Counter BindingsCompiled = Meter.CreateCounter("binding_compiled_total", description: "Number of bindings that were compiled. It should reach a steady state shortly after startup."); - /// Labeled by route=RouteName and request_type=GET/POST + /// Labeled by route=RouteName and request_type=Navigate/SpaNavigate/Command/StaticCommand public static readonly Histogram ViewModelSize = - Meter.CreateHistogram("viewmodel_size_bytes", unit: "bytes", description: "Size of the viewmodel JSON in bytes."); + Meter.CreateHistogram("viewmodel_size_bytes", unit: "bytes", description: "Size of the result viewmodel JSON in bytes."); - /// Labeled by route=RouteName and request_type=GET/POST + /// Labeled by route=RouteName and request_type=Navigate/SpaNavigate/Command/StaticCommand public static readonly Histogram ViewModelStringificationTime = Meter.CreateHistogram("viewmodel_stringification_seconds", unit: "seconds", description: "Time it took to stringify the resulting JSON view model."); - /// Labeled by route=RouteName and request_type=GET/POST + /// Labeled by route=RouteName and request_type=Navigate/SpaNavigate/Command/StaticCommand public static readonly Histogram ViewModelSerializationTime = Meter.CreateHistogram("viewmodel_serialization_seconds", unit: "seconds", description: "Time it took to serialize view model to JSON objects."); - /// Labeled by route=RouteName and lifecycle_type=TODO + /// Labeled by route=RouteName and lifecycle_type=PreInit/Init/Load/PreRender/PreRenderComplete public static readonly Histogram LifecycleInvocationDuration = - Meter.CreateHistogram("control_lifecycle_seconds", unit: "seconds", description: "Time it took to process a request on the specific route."); + Meter.CreateHistogram("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)."); - /// Labeled by route=RouteName, dothtml_file=filepath, request_type=GET/POST + /// Labeled by route=RouteName, dothtml_file=filepath, request_type=Navigate/SpaNavigate/Command/StaticCommand public static readonly Histogram RequestDuration = Meter.CreateHistogram("request_duration_seconds", unit: "seconds", description: "Time it took to process a request on the specific route."); - /// Labeled by route=RouteName, dothtml_file=filepath, request_type=GET/POST + /// Labeled by route=RouteName, request_type=Navigate/SpaNavigate/Command/StaticCommand public static readonly Counter RequestsRejected = Meter.CreateCounter("request_rejected_total", description: "Number of requests rejected (for security reasons) on the specific route."); /// Labeled by command="method invoked", result=Ok/Exception/UnhandledException public static readonly Histogram StaticCommandInvocationDuration = - Meter.CreateHistogram("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("!", 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\"}."); /// Labeled by command={command: TheBinding()}, result=Ok/Exception/UnhandledException public static readonly Histogram CommandInvocationDuration = - Meter.CreateHistogram("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("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\"}."); + /// Labeled by route=RouteName, request_type=Navigate/SpaNavigate/Command/StaticCommand public static readonly Histogram ValidationErrorsReturned = Meter.CreateHistogram("viewmodel_validation_errors_total", description: "Number of validation errors returned to the client."); @@ -100,6 +101,7 @@ public static class DotvvmMetrics Meter.CreateCounter("viewmodel_cache_loaded_bytes_total", "bytes", description: "Total number of bytes loaded from view model cache"); + /// Returns the default recommended buckets for the histograms defined in this class. public static double[]? TryGetRecommendedBuckets(Instrument instrument) { if (instrument.Meter != Meter) From 19b12764905b3e681285218053ba0fef455d7e6f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Standa=20Luke=C5=A1?= Date: Wed, 27 Sep 2023 13:23:37 +0200 Subject: [PATCH 2/2] Optimize DotvvmMetrics.ExponentialBuckets The stupid prometheus-net library call this function for every single datapoint... I didn't want to cache the result arrays, as we'd have to undo that optimization when we add some configuration arguments to the TryGetRecommendedBuckets method. --- .../Framework/Hosting/DotvvmMetrics.cs | 38 +++++++++++++------ src/Tests/Runtime/MetricsTests.cs | 29 ++++++++++++++ 2 files changed, 55 insertions(+), 12 deletions(-) create mode 100644 src/Tests/Runtime/MetricsTests.cs diff --git a/src/Framework/Framework/Hosting/DotvvmMetrics.cs b/src/Framework/Framework/Hosting/DotvvmMetrics.cs index 918edb5f9d..efabc3943d 100644 --- a/src/Framework/Framework/Hosting/DotvvmMetrics.cs +++ b/src/Framework/Framework/Hosting/DotvvmMetrics.cs @@ -112,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. @@ -143,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 RouteLabel(this IDotvvmRequestContext context) => diff --git a/src/Tests/Runtime/MetricsTests.cs b/src/Tests/Runtime/MetricsTests.cs new file mode 100644 index 0000000000..38fd93c8f0 --- /dev/null +++ b/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)); + + } + } +}