From 8f7f7780c29fca9f93aa1d32c03eb90a12520ae7 Mon Sep 17 00:00:00 2001 From: Victor Alfaro Date: Wed, 11 Oct 2023 11:05:38 -0600 Subject: [PATCH] More time metrics (#26398) --- .../analytics/bayesian/BayesianAPIImpl.java | 10 +- .../java/com/dotcms/cube/CubeJSClient.java | 22 ++-- .../business/ExperimentsAPIImpl.java | 5 + .../result/ExperimentAnalyzerUtil.java | 5 + .../com/dotcms/metrics/timing/TimeMetric.java | 110 ++++++++++++++++++ .../metrics/timing/TimeMetricHelper.java | 47 ++++++++ .../metrics/timing/TimeMetricHelperTest.java | 47 ++++++++ .../dotcms/metrics/timing/TimeMetricTest.java | 36 ++++++ 8 files changed, 263 insertions(+), 19 deletions(-) create mode 100644 dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetric.java create mode 100644 dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetricHelper.java create mode 100644 dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricHelperTest.java create mode 100644 dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricTest.java diff --git a/dotCMS/src/main/java/com/dotcms/analytics/bayesian/BayesianAPIImpl.java b/dotCMS/src/main/java/com/dotcms/analytics/bayesian/BayesianAPIImpl.java index d3f5d94f3f8a..825beafc6d4b 100644 --- a/dotCMS/src/main/java/com/dotcms/analytics/bayesian/BayesianAPIImpl.java +++ b/dotCMS/src/main/java/com/dotcms/analytics/bayesian/BayesianAPIImpl.java @@ -2,6 +2,7 @@ import com.dotcms.analytics.bayesian.beta.BetaDistributionWrapper; import com.dotcms.analytics.bayesian.model.*; +import com.dotcms.metrics.timing.TimeMetric; import com.dotmarketing.exception.DotDataException; import com.dotmarketing.util.Config; import com.dotmarketing.util.Logger; @@ -34,9 +35,7 @@ public class BayesianAPIImpl implements BayesianAPI { */ @Override public BayesianResult doBayesian(final BayesianInput input) { - final UUID metricId = UUID.randomUUID(); - final long start = System.currentTimeMillis(); - Logger.debug(this, String.format("BAYESIAN-CALCULATION [%s] START <<<<<", metricId)); + final TimeMetric timeMetric = TimeMetric.mark(getClass().getSimpleName()); // validate input final BayesianResult bayesianResult = noopFallback(input) @@ -44,10 +43,7 @@ public BayesianResult doBayesian(final BayesianInput input) { ? getAbBayesianResult(input) : getAbcBayesianResult(input)); - final long end = System.currentTimeMillis(); - Logger.debug( - this, - String.format("BAYESIAN-CALCULATION [%s] END - took [%d] secs >>>>>", metricId, (end - start) / 1000)); + timeMetric.stop(); return bayesianResult; } diff --git a/dotCMS/src/main/java/com/dotcms/cube/CubeJSClient.java b/dotCMS/src/main/java/com/dotcms/cube/CubeJSClient.java index cf4890092685..5fe3cad2914e 100644 --- a/dotCMS/src/main/java/com/dotcms/cube/CubeJSClient.java +++ b/dotCMS/src/main/java/com/dotcms/cube/CubeJSClient.java @@ -8,12 +8,12 @@ import com.dotcms.http.CircuitBreakerUrl; import com.dotcms.http.CircuitBreakerUrl.Method; import com.dotcms.http.CircuitBreakerUrl.Response; +import com.dotcms.metrics.timing.TimeMetric; import com.dotcms.util.DotPreconditions; import com.dotcms.util.JsonUtil; import com.dotmarketing.util.Logger; import com.dotmarketing.util.UtilMethods; import com.google.common.collect.ImmutableMap; -import org.jetbrains.annotations.NotNull; import javax.ws.rs.core.HttpHeaders; import java.io.IOException; @@ -21,7 +21,6 @@ import java.util.HashMap; import java.util.List; import java.util.Map; -import java.util.UUID; /** * CubeJS Client it allow to send a Request to a Cube JS Server. @@ -102,12 +101,13 @@ public CubeJSResultSet send(final CubeJSQuery query) { final CircuitBreakerUrl cubeJSClient; final String cubeJsUrl = String.format("%s/cubejs-api/v1/load", url); + final String queryAsString = query.toString(); try { cubeJSClient = CircuitBreakerUrl.builder() .setMethod(Method.GET) .setHeaders(cubeJsHeaders(accessToken)) .setUrl(cubeJsUrl) - .setParams(map("query", query.toString())) + .setParams(map("query", queryAsString)) .setTimeout(4000) .setThrowWhenNot2xx(false) .build(); @@ -115,7 +115,7 @@ public CubeJSResultSet send(final CubeJSQuery query) { throw new RuntimeException(e); } - final Response response = getStringResponse(cubeJSClient, cubeJsUrl); + final Response response = getStringResponse(cubeJSClient, cubeJsUrl, queryAsString); try { final String responseAsString = response.getResponse(); @@ -129,17 +129,15 @@ public CubeJSResultSet send(final CubeJSQuery query) { } } - private static Response getStringResponse(final CircuitBreakerUrl cubeJSClient, final String url) { - final long start = System.currentTimeMillis(); - final UUID metricId = UUID.randomUUID(); - Logger.debug(CubeJSClient.class, String.format("CUBEJS-REQUEST [%s] START <<<<<", metricId)); + private Response getStringResponse(final CircuitBreakerUrl cubeJSClient, + final String cubeJsUrl, + final String queryAsString) { + final TimeMetric timeMetric = TimeMetric.mark(getClass().getSimpleName()); + Logger.debug(this, String.format("Getting results from CubeJs [%s] with query [%s]", cubeJsUrl, queryAsString)); final Response response = cubeJSClient.doResponse(); - final long end = System.currentTimeMillis(); - Logger.debug( - CubeJSClient.class, - String.format("CUBEJS-REQUEST [%s] END - took [%d] secs >>>>>", metricId, (end - start) / 1000)); + timeMetric.stop(); if (!CircuitBreakerUrl.isWithin2xx(response.getStatusCode())) { throw new RuntimeException("CubeJS Server is not available"); diff --git a/dotCMS/src/main/java/com/dotcms/experiments/business/ExperimentsAPIImpl.java b/dotCMS/src/main/java/com/dotcms/experiments/business/ExperimentsAPIImpl.java index 4b6deceee2e8..711335786bb8 100644 --- a/dotCMS/src/main/java/com/dotcms/experiments/business/ExperimentsAPIImpl.java +++ b/dotCMS/src/main/java/com/dotcms/experiments/business/ExperimentsAPIImpl.java @@ -54,6 +54,7 @@ import com.dotcms.experiments.model.TargetingCondition; import com.dotcms.experiments.model.TrafficProportion; +import com.dotcms.metrics.timing.TimeMetric; import com.dotcms.rest.exception.NotFoundException; import com.dotcms.system.event.local.model.EventSubscriber; import com.dotcms.util.CollectionsUtils; @@ -1236,6 +1237,8 @@ private BayesianResult calcBayesian(final ExperimentResults experimentResults, f @Override public List getEvents(final Experiment experiment, final User user) throws DotDataException, DotSecurityException { + final TimeMetric timeMetric = TimeMetric.mark(getClass().getSimpleName() + ".getEvents()"); + final CubeJSClient cubeClient = cubeJSClientFactory.create(user); final CubeJSQuery cubeJSQuery = ExperimentResultsQueryFactory.INSTANCE .create(experiment); @@ -1280,6 +1283,8 @@ public List getEvents(final Experiment experiment, e.getMessage()); Logger.error(this, message, e); throw new DotDataException(message, e); + } finally { + timeMetric.stop(); } } diff --git a/dotCMS/src/main/java/com/dotcms/experiments/business/result/ExperimentAnalyzerUtil.java b/dotCMS/src/main/java/com/dotcms/experiments/business/result/ExperimentAnalyzerUtil.java index 233c029a6499..bb6929f1da19 100644 --- a/dotCMS/src/main/java/com/dotcms/experiments/business/result/ExperimentAnalyzerUtil.java +++ b/dotCMS/src/main/java/com/dotcms/experiments/business/result/ExperimentAnalyzerUtil.java @@ -20,6 +20,7 @@ import com.dotcms.experiments.model.ExperimentVariant; import com.dotcms.experiments.model.Goal.GoalType; import com.dotcms.experiments.model.Goals; +import com.dotcms.metrics.timing.TimeMetric; import com.dotmarketing.beans.Host; import com.dotmarketing.business.APILocator; import com.dotmarketing.business.FactoryLocator; @@ -78,6 +79,8 @@ public ExperimentResults getExperimentResult(final Experiment experiment, final List browserSessions) throws DotDataException, DotSecurityException { + final TimeMetric timeMetric = TimeMetric.mark(getClass().getSimpleName() + ".getExperimentResult()"); + final Goals goals = experiment.goals() .orElseThrow(() -> new IllegalArgumentException("The Experiment must have a Goal")); @@ -106,6 +109,8 @@ public ExperimentResults getExperimentResult(final Experiment experiment, analyzeBrowserSessions(browserSessions, primaryGoal, builder, experiment); } + timeMetric.stop(); + return builder.build(); } diff --git a/dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetric.java b/dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetric.java new file mode 100644 index 000000000000..747e05a936a8 --- /dev/null +++ b/dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetric.java @@ -0,0 +1,110 @@ +package com.dotcms.metrics.timing; + +import com.dotmarketing.util.Logger; +import org.apache.commons.lang3.StringUtils; + +import java.util.UUID; + +/** + * A utility class for measuring and formatting time metrics. + * + *

This class allows you to create and track time metrics, measure the duration, + * and format the duration in seconds using the default format. It also provides + * methods for equality comparison based on the metric's name.

+ * + * @author vico + */ +public class TimeMetric { + + private final String name; + private long start = Long.MIN_VALUE; + private long stop = Long.MIN_VALUE; + + private TimeMetric(final String name) { + final String metricId = UUID.randomUUID().toString(); + this.name = (StringUtils.isNotBlank(name) ? name + "_" : "") + metricId; + } + + public long getStart() { + return start; + } + + public long getStop() { + return stop; + } + + /** + * Factory method to create a new TimeMetric instance with a given name and start timing. + * + * @param name The name of the time metric. + * @return A new TimeMetric instance with the specified name and started timer. + */ + public static TimeMetric mark(final String name) { + return new TimeMetric(name).start(); + } + + /** + * Start the timer for the TimeMetric instance. + * + * @return The TimeMetric instance with the timer started. + */ + public TimeMetric start() { + start = System.currentTimeMillis(); + reportStart(); + return this; + } + + /** + * Stop the timer for the TimeMetric instance. + * + * @return The TimeMetric instance with the timer stopped. + */ + public TimeMetric stop() { + stop = System.currentTimeMillis(); + reportStop(); + return this; + } + + /** + * Get the name of the TimeMetric. + * + * @return The name of the TimeMetric. + */ + public String getName() { + return name; + } + + /** + * Get the duration of the TimeMetric in milliseconds. + * + * @return The duration of the TimeMetric in milliseconds. + * @throws IllegalStateException if the TimeMetric is not started or stopped. + */ + public long getDuration() { + if (start == Long.MIN_VALUE || stop == Long.MIN_VALUE) { + throw new IllegalStateException("TimeMetric not started or stopped"); + } + return stop - start; + } + + /** + * Report the start of a time metric. + */ + private void reportStart() { + Logger.debug(this, String.format(">>>>> START [%s] at [%d]", getName(), getStart())); + } + + /** + * Report the stop of a time metric. + */ + private void reportStop() { + Logger.debug( + this, + String.format( + "<<<<< STOP [%s] at [%d] / duration [%s]", + getName(), + getStop(), + TimeMetricHelper.get().formatDuration(this))); + } + +} diff --git a/dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetricHelper.java b/dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetricHelper.java new file mode 100644 index 000000000000..8c858ee11c68 --- /dev/null +++ b/dotCMS/src/main/java/com/dotcms/metrics/timing/TimeMetricHelper.java @@ -0,0 +1,47 @@ +package com.dotcms.metrics.timing; + +import io.vavr.Lazy; + + +/** + * Utility class for formatting time metrics. + * + * @author vico + */ +public class TimeMetricHelper { + + private static final Lazy INSTANCE = Lazy.of(TimeMetricHelper::new); + + private TimeMetricHelper() {} + + /** + * Get an instance of the {@link TimeMetricHelper} class. + * + * @return The singleton instance of {@link TimeMetricHelper}. + */ + public static TimeMetricHelper get() { + return INSTANCE.get(); + } + + /** + * Format a time metric in seconds using a custom mask. + * + * @param timeMetric The time metric to format. + * @param mask The custom format mask (e.g., "%.2f"). + * @return The formatted string representing the time metric. + */ + public String formatDuration(final TimeMetric timeMetric, final String mask) { + return String.format(mask, (float) timeMetric.getDuration() / 1000); + } + + /** + * Format a time metric in seconds using the default mask "%.4f". + * + * @param timeMetric The time metric to format. + * @return The formatted string representing the time metric. + */ + public String formatDuration(final TimeMetric timeMetric) { + return formatDuration(timeMetric, "%.4f"); + } + +} diff --git a/dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricHelperTest.java b/dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricHelperTest.java new file mode 100644 index 000000000000..801f74155d7d --- /dev/null +++ b/dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricHelperTest.java @@ -0,0 +1,47 @@ +package com.dotcms.metrics.timing; + +import com.dotcms.UnitTestBase; +import org.junit.Before; +import org.junit.Test; + +import static graphql.Assert.assertTrue; + +/** + * Unit tests for the {@link TimeMetricHelper} class. + * + * @author vico + */ +public class TimeMetricHelperTest extends UnitTestBase { + + private TimeMetricHelper timeMetricHelper; + + @Before + public void setUp() { + timeMetricHelper = TimeMetricHelper.get(); + } + + /** + * Test the {@link TimeMetricHelper#formatDuration(TimeMetric, String)} method with a custom mask. + */ + @Test + public void testFormatSecondsWithCustomMask() throws InterruptedException { + final TimeMetric timeMetric = TimeMetric.mark("some-time-metric"); + Thread.sleep(100); + timeMetric.stop(); + final String formatted = timeMetricHelper.formatDuration(timeMetric, "%.2f"); + assertTrue(formatted.startsWith("0.1")); + } + + /** + * Test the {@link TimeMetricHelper#formatDuration(TimeMetric)} method with the default mask. + */ + @Test + public void testFormatSecondsWithDefaultMask() throws InterruptedException { + final TimeMetric timeMetric = TimeMetric.mark("some-time-metric"); + Thread.sleep(100); + timeMetric.stop(); + final String formatted = timeMetricHelper.formatDuration(timeMetric); + assertTrue(formatted.startsWith("0.10")); + } + +} diff --git a/dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricTest.java b/dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricTest.java new file mode 100644 index 000000000000..d61e7bc6a039 --- /dev/null +++ b/dotCMS/src/test/java/com/dotcms/metrics/timing/TimeMetricTest.java @@ -0,0 +1,36 @@ +package com.dotcms.metrics.timing; + +import com.dotcms.UnitTestBase; +import org.junit.Before; +import org.junit.Test; + +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertTrue; + +/** + * Unit tests for the {@link TimeMetric} class. + */ +public class TimeMetricTest extends UnitTestBase { + + private TimeMetric timeMetric; + + /** + * Set up the test environment by initializing the {@link TimeMetric} instance. + */ + @Before + public void setUp() { + timeMetric = TimeMetric.mark("TestMetric"); + } + + /** + * Test the stop() method of the {@link TimeMetric} class. + */ + @Test + public void testStartAndStop() { + assertNotNull("TimeMetric instance should not be null", timeMetric); + timeMetric.start(); + assertTrue("Timer should be stopped after calling stop()", timeMetric.stop().getDuration() >= 0); + } + +} +