From 2b28a3074c2665f1380c02a3e8f11cc32086dbf5 Mon Sep 17 00:00:00 2001 From: Robert von Burg Date: Mon, 21 Oct 2024 12:10:53 +0200 Subject: [PATCH] [New] Added a statistics API for TX, search and services --- .../li/strolch/agent/api/AgentStatistics.java | 39 ++++++ .../java/li/strolch/agent/api/Statistics.java | 111 ++++++++++++++++++ .../li/strolch/agent/api/StrolchAgent.java | 7 ++ .../persistence/api/AbstractTransaction.java | 8 +- .../persistence/api/ArchiveTransaction.java | 3 +- .../persistence/api/TransactionResult.java | 61 ++++------ .../java/li/strolch/search/StrolchSearch.java | 7 +- .../service/api/DefaultServiceHandler.java | 33 ++++-- .../strolch/rest/endpoint/AgentResource.java | 13 +- 9 files changed, 233 insertions(+), 49 deletions(-) create mode 100644 strolch-agent/src/main/java/li/strolch/agent/api/AgentStatistics.java create mode 100644 strolch-agent/src/main/java/li/strolch/agent/api/Statistics.java diff --git a/strolch-agent/src/main/java/li/strolch/agent/api/AgentStatistics.java b/strolch-agent/src/main/java/li/strolch/agent/api/AgentStatistics.java new file mode 100644 index 000000000..d03182e80 --- /dev/null +++ b/strolch-agent/src/main/java/li/strolch/agent/api/AgentStatistics.java @@ -0,0 +1,39 @@ +package li.strolch.agent.api; + +import com.google.gson.JsonObject; +import li.strolch.persistence.api.TransactionResult; + +import java.time.Duration; + +public class AgentStatistics { + + private final Statistics transactions; + private final Statistics searches; + private final Statistics services; + + public AgentStatistics() { + this.transactions = new Statistics(); + this.searches = new Statistics(); + this.services = new Statistics(); + } + + public JsonObject toJson() { + JsonObject json = new JsonObject(); + json.add("transactions", this.transactions.toJson()); + json.add("searches", this.searches.toJson()); + json.add("services", this.services.toJson()); + return json; + } + + public void recordTransaction(TransactionResult result) { + this.transactions.recordEvent(Duration.ofNanos(result.getTxDuration())); + } + + public void recordSearch(long durationNanos) { + this.searches.recordEvent(Duration.ofNanos(durationNanos)); + } + + public void recordService(long durationNanos) { + this.services.recordEvent(Duration.ofNanos(durationNanos)); + } +} diff --git a/strolch-agent/src/main/java/li/strolch/agent/api/Statistics.java b/strolch-agent/src/main/java/li/strolch/agent/api/Statistics.java new file mode 100644 index 000000000..2fd19cb59 --- /dev/null +++ b/strolch-agent/src/main/java/li/strolch/agent/api/Statistics.java @@ -0,0 +1,111 @@ +package li.strolch.agent.api; + +import com.google.gson.JsonObject; +import com.google.gson.JsonPrimitive; + +import java.time.Duration; +import java.time.LocalDateTime; +import java.time.temporal.ChronoUnit; +import java.util.LinkedList; +import java.util.List; +import java.util.Queue; +import java.util.stream.Collectors; + +import static java.time.temporal.ChronoUnit.*; + +public class Statistics { + + private final Queue events; + + public Statistics() { + this.events = new LinkedList<>(); + } + + public void recordEvent(Duration duration) { + LocalDateTime now = LocalDateTime.now(); + this.events.add(new Statistic(now, duration)); + removeOldEvents(now); + } + + private void removeOldEvents(LocalDateTime now) { + while (!this.events.isEmpty() && DAYS.between(this.events.peek().timestamp, now) >= 1) { + this.events.poll(); + } + } + + public int getLastMinute() { + return getInTimeFrame(1, MINUTES); + } + + public int getLast5Minutes() { + return getInTimeFrame(5, MINUTES); + } + + public int getLast15Minutes() { + return getInTimeFrame(15, MINUTES); + } + + public int getLastHour() { + return getInTimeFrame(1, HOURS); + } + + public int getLastDay() { + return getInTimeFrame(1, DAYS); + } + + private int getInTimeFrame(long amount, ChronoUnit unit) { + LocalDateTime now = LocalDateTime.now(); + return (int) this.events + .stream() + .filter(tx -> SECONDS.between(tx.timestamp, now) < unit.getDuration().getSeconds() * amount) + .count(); + } + + public JsonObject toJson() { + List durations = this.events.stream().map(e -> e.duration).toList(); + + long count = durations.size(); + long sum = durations.stream().mapToLong(Duration::toMillis).sum(); + int avg = count == 0 ? 0 : (int) ((double) sum / count); + + Duration min = durations.stream().min(Duration::compareTo).orElse(Duration.ZERO); + Duration max = durations.stream().max(Duration::compareTo).orElse(Duration.ZERO); + Duration median = getMedian(durations); + + JsonObject jsonObject = new JsonObject(); + jsonObject.addProperty("lastMinute", getLastMinute()); + jsonObject.addProperty("last5Minutes", getLast5Minutes()); + jsonObject.addProperty("last15Minutes", getLast15Minutes()); + jsonObject.addProperty("lastHour", getLastHour()); + jsonObject.addProperty("lastDay", getLastDay()); + jsonObject.addProperty("minDuration", min.toMillis()); + jsonObject.addProperty("maxDuration", max.toMillis()); + jsonObject.addProperty("avgDuration", avg); + jsonObject.addProperty("medianDuration", median.toMillis()); + + return jsonObject; + } + + private Duration getMedian(List durations) { + if (durations.isEmpty()) { + return Duration.ZERO; + } + List sorted = durations.stream().sorted().toList(); + int middle = sorted.size() / 2; + if (sorted.size() % 2 == 0) { + return sorted.get(middle - 1).plus(sorted.get(middle)).dividedBy(2); + } else { + return sorted.get(middle); + } + } + + private static class Statistic { + LocalDateTime timestamp; + Duration duration; + + Statistic(LocalDateTime timestamp, Duration duration) { + this.timestamp = timestamp; + this.duration = duration; + } + } +} \ No newline at end of file diff --git a/strolch-agent/src/main/java/li/strolch/agent/api/StrolchAgent.java b/strolch-agent/src/main/java/li/strolch/agent/api/StrolchAgent.java index 637713f4c..d3cdfce61 100644 --- a/strolch-agent/src/main/java/li/strolch/agent/api/StrolchAgent.java +++ b/strolch-agent/src/main/java/li/strolch/agent/api/StrolchAgent.java @@ -77,8 +77,15 @@ public class StrolchAgent { private VersionQueryResult versionQueryResult; + private final AgentStatistics agentStatistics; + public StrolchAgent(StrolchVersion appVersion) { this.appVersion = appVersion; + this.agentStatistics = new AgentStatistics(); + } + + public AgentStatistics getAgentStatistics() { + return this.agentStatistics; } public StrolchConfiguration getStrolchConfiguration() { diff --git a/strolch-agent/src/main/java/li/strolch/persistence/api/AbstractTransaction.java b/strolch-agent/src/main/java/li/strolch/persistence/api/AbstractTransaction.java index a77102b35..f97d0992e 100644 --- a/strolch-agent/src/main/java/li/strolch/persistence/api/AbstractTransaction.java +++ b/strolch-agent/src/main/java/li/strolch/persistence/api/AbstractTransaction.java @@ -38,6 +38,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import java.time.LocalDateTime; import java.util.*; import java.util.concurrent.TimeUnit; import java.util.stream.Stream; @@ -68,7 +69,7 @@ public abstract class AbstractTransaction implements StrolchTransaction { private final MapOfMaps activityCache; private TransactionCloseStrategy closeStrategy; - private long globalSilentThreshold; + private final long globalSilentThreshold; private long silentThreshold; private boolean suppressUpdates; private boolean suppressAudits; @@ -107,7 +108,7 @@ public AbstractTransaction(ComponentContainer container, StrolchRealm realm, Cer this.flushedCommands = new ArrayList<>(); this.lockedElements = new HashSet<>(); this.closeStrategy = readOnly ? TransactionCloseStrategy.READ_ONLY : TransactionCloseStrategy.DEFAULT; - this.txResult = new TransactionResult(getRealmName(), System.nanoTime(), new Date()); + this.txResult = new TransactionResult(getRealmName(), System.nanoTime(), LocalDateTime.now()); this.txResult.setState(TransactionState.OPEN); this.objectFilter = new ObjectFilter(); @@ -1746,6 +1747,9 @@ public void close() throws StrolchTransactionException { } finally { releaseElementLocks(); TransactionThreadLocal.removeTx(); + + // record the event + getAgent().getAgentStatistics().recordTransaction(this.txResult); } } diff --git a/strolch-agent/src/main/java/li/strolch/persistence/api/ArchiveTransaction.java b/strolch-agent/src/main/java/li/strolch/persistence/api/ArchiveTransaction.java index 35e577b9d..f39706821 100644 --- a/strolch-agent/src/main/java/li/strolch/persistence/api/ArchiveTransaction.java +++ b/strolch-agent/src/main/java/li/strolch/persistence/api/ArchiveTransaction.java @@ -7,6 +7,7 @@ import li.strolch.model.activity.Activity; import li.strolch.utils.collections.DateRange; +import java.time.LocalDateTime; import java.util.Date; import java.util.List; @@ -26,7 +27,7 @@ public abstract class ArchiveTransaction implements AutoCloseable { protected ArchiveTransaction(StrolchTransaction tx, DataArchiveHandler archiveHandler) { this.tx = tx; this.archiveHandler = archiveHandler; - this.txResult = new TransactionResult(tx.getRealmName(), System.nanoTime(), new Date()); + this.txResult = new TransactionResult(tx.getRealmName(), System.nanoTime(), LocalDateTime.now()); } public StrolchTransaction tx() { diff --git a/strolch-agent/src/main/java/li/strolch/persistence/api/TransactionResult.java b/strolch-agent/src/main/java/li/strolch/persistence/api/TransactionResult.java index 23d5eecca..81216be4b 100644 --- a/strolch-agent/src/main/java/li/strolch/persistence/api/TransactionResult.java +++ b/strolch-agent/src/main/java/li/strolch/persistence/api/TransactionResult.java @@ -1,12 +1,12 @@ /* * Copyright 2013 Robert von Burg - * + * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at - * + * * http://www.apache.org/licenses/LICENSE-2.0 - * + * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. @@ -17,7 +17,7 @@ import li.strolch.utils.helper.StringHelper; -import java.util.Date; +import java.time.LocalDateTime; public class TransactionResult { @@ -26,7 +26,7 @@ public class TransactionResult { private Exception failCause; private final long startNanos; - private Date startTime; + private LocalDateTime startTime; private long txDuration; private long closeDuration; @@ -35,7 +35,7 @@ public class TransactionResult { private long updated; private long deleted; - public TransactionResult(String realm, long startNanos, Date startDate) { + public TransactionResult(String realm, long startNanos, LocalDateTime startDate) { this.realm = realm; this.startNanos = startNanos; this.startTime = startDate; @@ -57,8 +57,7 @@ public TransactionState getState() { } /** - * @param state - * the state to set + * @param state the state to set */ public void setState(TransactionState state) { this.state = state; @@ -72,8 +71,7 @@ public Exception getFailCause() { } /** - * @param failCause - * the failCause to set + * @param failCause the failCause to set */ public void setFailCause(Exception failCause) { this.failCause = failCause; @@ -89,15 +87,14 @@ public long getStartNanos() { /** * @return the startTime */ - public Date getStartTime() { + public LocalDateTime getStartTime() { return this.startTime; } /** - * @param startTime - * the startTime to set + * @param startTime the startTime to set */ - public void setStartTime(Date startTime) { + public void setStartTime(LocalDateTime startTime) { this.startTime = startTime; } @@ -109,8 +106,7 @@ public long getTxDuration() { } /** - * @param txDuration - * the txDuration to set + * @param txDuration the txDuration to set */ public void setTxDuration(long txDuration) { this.txDuration = txDuration; @@ -124,8 +120,7 @@ public long getCloseDuration() { } /** - * @param closeDuration - * the closeDuration to set + * @param closeDuration the closeDuration to set */ public void setCloseDuration(long closeDuration) { this.closeDuration = closeDuration; @@ -139,8 +134,7 @@ public long getCreated() { } /** - * @param created - * the created to set + * @param created the created to set */ public void setCreated(long created) { this.created = created; @@ -154,8 +148,7 @@ public long getRead() { } /** - * @param read - * the read to set + * @param read the read to set */ public void setRead(long read) { this.read = read; @@ -169,8 +162,7 @@ public long getUpdated() { } /** - * @param updated - * the updated to set + * @param updated the updated to set */ public void setUpdated(long updated) { this.updated = updated; @@ -184,8 +176,7 @@ public long getDeleted() { } /** - * @param deleted - * the deleted to set + * @param deleted the deleted to set */ public void setDeleted(long deleted) { this.deleted = deleted; @@ -215,15 +206,15 @@ public String getLogMessage() { StringBuilder sb = new StringBuilder(); switch (this.state) { - case OPEN -> sb.append("TX is still open after "); - case COMMITTED -> sb.append("TX was completed after "); - case ROLLED_BACK -> sb.append("TX was rolled back after "); - case FAILED -> sb.append("TX has failed after "); - default -> { - sb.append("TX is in unhandled state "); - sb.append(this.state); - sb.append(" after "); - } + case OPEN -> sb.append("TX is still open after "); + case COMMITTED -> sb.append("TX was completed after "); + case ROLLED_BACK -> sb.append("TX was rolled back after "); + case FAILED -> sb.append("TX has failed after "); + default -> { + sb.append("TX is in unhandled state "); + sb.append(this.state); + sb.append(" after "); + } } sb.append(StringHelper.formatNanoDuration(this.txDuration)); diff --git a/strolch-agent/src/main/java/li/strolch/search/StrolchSearch.java b/strolch-agent/src/main/java/li/strolch/search/StrolchSearch.java index 510b03782..f0f1a66a3 100644 --- a/strolch-agent/src/main/java/li/strolch/search/StrolchSearch.java +++ b/strolch-agent/src/main/java/li/strolch/search/StrolchSearch.java @@ -89,11 +89,16 @@ public StrolchSearch internal() { * * @return the search result */ - public abstract RootElementSearchResult search(StrolchTransaction tx); public final U search(StrolchTransaction tx) { long start = System.nanoTime(); + try { Stream stream = prepareSearch(tx); return evaluateResult(stream); + } finally { + // record the event + long duration = System.nanoTime() - start; + tx.getAgent().getAgentStatistics().recordSearch(duration); + } } protected abstract U evaluateResult(Stream stream); diff --git a/strolch-agent/src/main/java/li/strolch/service/api/DefaultServiceHandler.java b/strolch-agent/src/main/java/li/strolch/service/api/DefaultServiceHandler.java index a4df6bd6d..2c2804fa2 100644 --- a/strolch-agent/src/main/java/li/strolch/service/api/DefaultServiceHandler.java +++ b/strolch-agent/src/main/java/li/strolch/service/api/DefaultServiceHandler.java @@ -39,6 +39,7 @@ import static li.strolch.model.Tags.AGENT; import static li.strolch.service.api.ServiceResultState.*; +import static li.strolch.utils.helper.ExceptionHelper.getRootCauseMessage; import static li.strolch.utils.helper.StringHelper.formatNanoDuration; import static li.strolch.utils.helper.StringHelper.isNotEmpty; @@ -115,8 +116,21 @@ public U doService(Certific } catch (Exception e) { long end = System.nanoTime(); String msg = "User {0}: Service failed {1} after {2} due to {3}"; + String reason = getRootCauseMessage(e); msg = MessageFormat.format(msg, username, service.getClass().getName(), formatNanoDuration(end - start), - e.getMessage()); + reason); + + ResourceBundle bundle = ResourceBundle.getBundle("strolch-agent"); + LogMessage logMessage = new LogMessage(getRealmName(argument, certificate), username, + Locator.valueOf(AGENT, Service.class.getSimpleName(), service.getClass().getName()), + LogSeverity.Exception, LogMessageState.Information, bundle, "agent.service.failed.ex") + .value("service", service.getClass().getName()) + .value("reason", reason) + .value("exception", e); + + OperationsLog operationsLog = getContainer().getComponent(OperationsLog.class); + operationsLog.addMessage(logMessage); + logger.error(msg); throw new StrolchException(msg, e); } @@ -125,7 +139,7 @@ public U doService(Certific private I18nMessage logAccessDenied(Certificate certificate, T argument, AbstractService service, long start, String username, PrivilegeException e) { logger.error(buildFailMessage(service, start, username, e)); - addAccessDeniedLogMessage(certificate, argument, service, username, e, service.getClass().getName()); + addAccessDeniedLogMessage(certificate, argument, username, e, service.getClass().getName()); I18nMessage i18n = buildAccessDeniedMessage(certificate, service, username); logger.error(e.getMessage(), e); return i18n; @@ -158,8 +172,8 @@ private static String build return msg; } - private void addAccessDeniedLogMessage(Certificate certificate, - T argument, AbstractService service, String username, PrivilegeException e, String svcName) { + private void addAccessDeniedLogMessage(Certificate certificate, T argument, + String username, PrivilegeException e, String svcName) { if (getContainer().hasComponent(OperationsLog.class)) { String realmName = getRealmName(argument, certificate); LogMessage logMessage = new LogMessage(realmName, username, @@ -201,7 +215,8 @@ private void logResult(Service service, ServiceArgument arg, long start, C String realmName = getRealmName(arg, certificate); - msg = MessageFormat.format(msg, username, svcName, formatNanoDuration(end - start)); + long durationNanos = end - start; + msg = MessageFormat.format(msg, username, svcName, formatNanoDuration(durationNanos)); if (result.getState() == SUCCESS) { logger.info(msg); @@ -215,7 +230,7 @@ private void logResult(Service service, ServiceArgument arg, long start, C } else if (isNotEmpty(result.getMessage())) { logger.warn("Reason: {}", result.getMessage()); } else if (result.getThrowable() != null) { - logger.warn("Reason: {}", result.getThrowable().getMessage(), result.getThrowable()); + logger.warn("Reason: {}", getRootCauseMessage(result.getThrowable()), result.getThrowable()); } } else if (result.getState() == FAILED @@ -233,7 +248,7 @@ private void logResult(Service service, ServiceArgument arg, long start, C } else if (isNotEmpty(result.getMessage())) { reason = result.getMessage(); } else if (result.getThrowable() != null) { - reason = result.getThrowable().getMessage(); + reason = getRootCauseMessage(result.getThrowable()); throwable = result.getThrowable(); } @@ -258,7 +273,6 @@ && getContainer().hasComponent(OperationsLog.class)) { logMessage = new LogMessage(realmName, username, Locator.valueOf(AGENT, Service.class.getSimpleName(), svcName), LogSeverity.Exception, LogMessageState.Information, bundle, "agent.service.failed.ex") - .withException(throwable) .value("service", svcName) .value("reason", reason) .value("exception", throwable); @@ -275,5 +289,8 @@ && getContainer().hasComponent(OperationsLog.class)) { logger.error("UNHANDLED SERVICE RESULT STATE: {}", result.getState()); logger.error(msg); } + + // record the event + getAgent().getAgentStatistics().recordService(durationNanos); } } diff --git a/strolch-web-rest/src/main/java/li/strolch/rest/endpoint/AgentResource.java b/strolch-web-rest/src/main/java/li/strolch/rest/endpoint/AgentResource.java index 236f9770b..3603fad5d 100644 --- a/strolch-web-rest/src/main/java/li/strolch/rest/endpoint/AgentResource.java +++ b/strolch-web-rest/src/main/java/li/strolch/rest/endpoint/AgentResource.java @@ -29,11 +29,20 @@ public class AgentResource { private static final Logger logger = LoggerFactory.getLogger(AgentResource.class); - private static Certificate validateCertificate(HttpServletRequest request) { + private static void validateCertificate(HttpServletRequest request) { Certificate cert = (Certificate) request.getAttribute(STROLCH_CERTIFICATE); RestfulStrolchComponent rest = RestfulStrolchComponent.getInstance(); rest.validate(cert).validateAction(Tags.AGENT, getCallerMethodNoClass(2)); - return cert; + } + + @GET + @Path("statistics") + @Produces(MediaType.APPLICATION_JSON) + public Response getStatistics(@Context HttpServletRequest request) { + validateCertificate(request); + StrolchAgent agent = RestfulStrolchComponent.getInstance().getAgent(); + JsonObject statisticsJson = agent.getAgentStatistics().toJson(); + return ResponseUtil.toResponse(DATA, statisticsJson); } @PUT