From e48f50e91b4f268199fc5b40f9913154f227fd16 Mon Sep 17 00:00:00 2001 From: lucio Date: Wed, 1 Feb 2023 17:18:13 +0100 Subject: [PATCH] added automatic metrics for micrometer --- .../java/org/gcube/smartgears/Bootstrap.java | 8 +- .../java/org/gcube/smartgears/Constants.java | 5 + .../ApplicationConfigurationBinder.java | 2 + .../DefaultApplicationContext.java | 1 - .../handlers/application/RequestHandler.java | 4 + .../lifecycle/ApplicationProfileManager.java | 5 +- .../request/RequestAccounting.java | 91 ++++++++++--------- .../application/request/RequestMetrics.java | 48 ++++++++++ .../smartgears/managers/RequestManager.java | 51 ++--------- 9 files changed, 126 insertions(+), 89 deletions(-) create mode 100644 src/main/java/org/gcube/smartgears/handlers/application/request/RequestMetrics.java diff --git a/src/main/java/org/gcube/smartgears/Bootstrap.java b/src/main/java/org/gcube/smartgears/Bootstrap.java index f5df24a..ad52fd8 100644 --- a/src/main/java/org/gcube/smartgears/Bootstrap.java +++ b/src/main/java/org/gcube/smartgears/Bootstrap.java @@ -16,9 +16,11 @@ import org.slf4j.LoggerFactory; import io.micrometer.core.instrument.Metrics; import io.micrometer.core.instrument.binder.jvm.ClassLoaderMetrics; +import io.micrometer.core.instrument.binder.jvm.JvmGcMetrics; import io.micrometer.core.instrument.binder.jvm.JvmMemoryMetrics; import io.micrometer.core.instrument.binder.jvm.JvmThreadMetrics; import io.micrometer.core.instrument.binder.system.ProcessorMetrics; +import io.micrometer.core.instrument.binder.system.UptimeMetrics; import io.micrometer.prometheus.PrometheusConfig; import io.micrometer.prometheus.PrometheusMeterRegistry; @@ -95,12 +97,14 @@ public class Bootstrap implements ServletContainerInitializer { context = ProviderFactory.provider().containerContext(); PrometheusMeterRegistry registry = new PrometheusMeterRegistry(PrometheusConfig.DEFAULT); - registry = new PrometheusMeterRegistry(PrometheusConfig.DEFAULT); + new ClassLoaderMetrics().bindTo(registry); new JvmMemoryMetrics().bindTo(registry); - //new JvmGcMetrics().bindTo(registry); + new JvmGcMetrics().bindTo(registry); new ProcessorMetrics().bindTo(registry); new JvmThreadMetrics().bindTo(registry); + new UptimeMetrics().bindTo(registry); + new ProcessorMetrics().bindTo(registry); Metrics.addRegistry(registry); diff --git a/src/main/java/org/gcube/smartgears/Constants.java b/src/main/java/org/gcube/smartgears/Constants.java index 3db496f..ea1e571 100644 --- a/src/main/java/org/gcube/smartgears/Constants.java +++ b/src/main/java/org/gcube/smartgears/Constants.java @@ -98,6 +98,11 @@ public class Constants { */ public static final String request_validation = "request-validation"; + /** + * The configuration name of {@link RequestMetrics}s. + */ + public static final String request_metrics = "request-metrics"; + /** * The configuration name of {@link RequestValidator}s. */ diff --git a/src/main/java/org/gcube/smartgears/configuration/application/ApplicationConfigurationBinder.java b/src/main/java/org/gcube/smartgears/configuration/application/ApplicationConfigurationBinder.java index e12e04d..d31bf64 100644 --- a/src/main/java/org/gcube/smartgears/configuration/application/ApplicationConfigurationBinder.java +++ b/src/main/java/org/gcube/smartgears/configuration/application/ApplicationConfigurationBinder.java @@ -19,6 +19,7 @@ import org.gcube.smartgears.handlers.application.ApplicationLifecycleHandler; import org.gcube.smartgears.handlers.application.RequestHandler; import org.gcube.smartgears.handlers.application.lifecycle.ApplicationProfileManager; import org.gcube.smartgears.handlers.application.request.RequestAccounting; +import org.gcube.smartgears.handlers.application.request.RequestMetrics; import org.gcube.smartgears.handlers.application.request.RequestValidator; /** @@ -66,6 +67,7 @@ public class ApplicationConfigurationBinder { List requestHandlers = new LinkedList(); //ADDING BASE Handler (order is important) + requestHandlers.add(new RequestMetrics()); requestHandlers.add(new RequestValidator()); requestHandlers.add(new RequestAccounting()); diff --git a/src/main/java/org/gcube/smartgears/context/application/DefaultApplicationContext.java b/src/main/java/org/gcube/smartgears/context/application/DefaultApplicationContext.java index 4e0b443..7aeeea8 100644 --- a/src/main/java/org/gcube/smartgears/context/application/DefaultApplicationContext.java +++ b/src/main/java/org/gcube/smartgears/context/application/DefaultApplicationContext.java @@ -6,7 +6,6 @@ import org.gcube.common.events.Hub; import org.gcube.smartgears.configuration.application.ApplicationConfiguration; import org.gcube.smartgears.context.Properties; import org.gcube.smartgears.context.container.ContainerContext; -import org.gcube.smartgears.health.HealthManager; import org.gcube.smartgears.lifecycle.application.ApplicationLifecycle; import org.gcube.smartgears.persistence.PersistenceWriter; import org.gcube.smartgears.security.AuthorizationProvider; diff --git a/src/main/java/org/gcube/smartgears/handlers/application/RequestHandler.java b/src/main/java/org/gcube/smartgears/handlers/application/RequestHandler.java index 07f83e2..95fa9d2 100644 --- a/src/main/java/org/gcube/smartgears/handlers/application/RequestHandler.java +++ b/src/main/java/org/gcube/smartgears/handlers/application/RequestHandler.java @@ -22,6 +22,10 @@ public abstract class RequestHandler extends AbstractHandler implements Applicat abstract public String getName(); + public boolean isUnfiltrable() { + return false; + } + /** * Initialises the handler. * diff --git a/src/main/java/org/gcube/smartgears/handlers/application/lifecycle/ApplicationProfileManager.java b/src/main/java/org/gcube/smartgears/handlers/application/lifecycle/ApplicationProfileManager.java index 25d2cf1..8c9eafe 100644 --- a/src/main/java/org/gcube/smartgears/handlers/application/lifecycle/ApplicationProfileManager.java +++ b/src/main/java/org/gcube/smartgears/handlers/application/lifecycle/ApplicationProfileManager.java @@ -83,8 +83,9 @@ public class ApplicationProfileManager extends ApplicationLifecycleHandler { publishers = context.container().configuration().mode()!=Mode.offline? ProviderFactory.provider().publishers(): Collections.emptyList(); - registerObservers(); - schedulePeriodicUpdates(); + + registerObservers(); + schedulePeriodicUpdates(); } // helpers diff --git a/src/main/java/org/gcube/smartgears/handlers/application/request/RequestAccounting.java b/src/main/java/org/gcube/smartgears/handlers/application/request/RequestAccounting.java index a815151..c51990e 100644 --- a/src/main/java/org/gcube/smartgears/handlers/application/request/RequestAccounting.java +++ b/src/main/java/org/gcube/smartgears/handlers/application/request/RequestAccounting.java @@ -1,7 +1,5 @@ package org.gcube.smartgears.handlers.application.request; -import java.util.concurrent.TimeUnit; - import org.gcube.accounting.datamodel.UsageRecord.OperationResult; import org.gcube.accounting.datamodel.usagerecords.ServiceUsageRecord; import org.gcube.accounting.persistence.AccountingPersistence; @@ -17,13 +15,11 @@ import org.gcube.smartgears.utils.InnerMethodName; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import io.micrometer.core.instrument.Metrics; - public class RequestAccounting extends RequestHandler { private static Logger log = LoggerFactory.getLogger(RequestAccounting.class); - private static ThreadLocal startCallThreadLocal = new ThreadLocal(); + private static ThreadLocal startCallThreadLocal = new ThreadLocal(); private static final String UNKNOWN = "Unknown"; @@ -36,24 +32,24 @@ public class RequestAccounting extends RequestHandler { public void handleRequest(RequestEvent e) { ApplicationContext appContext = e.context(); - String context = getContext(appContext); - if (InnerMethodName.instance.get()==null) { + if (InnerMethodName.instance.get() == null) { String calledMethod = e.request().getRequestURI().substring(e.request().getContextPath().length()); if (calledMethod.isEmpty()) calledMethod = "/"; - calledMethod= e.request().getMethod()+" "+calledMethod; + calledMethod = e.request().getMethod() + " " + calledMethod; InnerMethodName.instance.set(calledMethod); } - String caller = SecretManagerProvider.instance.get()!=null ? SecretManagerProvider.instance.get().getOwner().getId(): - UNKNOWN; + String caller = SecretManagerProvider.instance.get() != null + ? SecretManagerProvider.instance.get().getOwner().getId() + : UNKNOWN; startCallThreadLocal.set(System.currentTimeMillis()); - log.info("REQUEST START ON {}:{}({}) CALLED FROM {}@{} IN SCOPE {} ", - appContext.configuration().name(),appContext.configuration().serviceClass(), InnerMethodName.instance.get(), - caller, e.request().getRemoteHost(), context ); + log.info("REQUEST START ON {}:{}({}) CALLED FROM {}@{} IN SCOPE {} ", appContext.configuration().name(), + appContext.configuration().serviceClass(), InnerMethodName.instance.get(), caller, + e.request().getRemoteHost(), context); } @@ -65,33 +61,41 @@ public class RequestAccounting extends RequestHandler { String context = getContext(appContext); - String caller = SecretManagerProvider.instance.get()!=null ? SecretManagerProvider.instance.get().getOwner().getId(): - UNKNOWN; + String caller = SecretManagerProvider.instance.get() != null + ? SecretManagerProvider.instance.get().getOwner().getId() + : UNKNOWN; String callerQualifier = UNKNOWN; - //retieves caller Ip when there is a proxy + // retieves caller Ip when there is a proxy String callerIp = e.request().getHeader("x-forwarded-for"); - if(callerIp==null) - callerIp=e.request().getRemoteHost(); + if (callerIp == null) + callerIp = e.request().getRemoteHost(); - boolean success = e.response().getStatus()<400; + boolean success = e.response().getStatus() < 400; - if (appContext.container().configuration().mode()!=Mode.offline) - generateAccounting(caller,callerQualifier,callerIp==null?UNKNOWN:callerIp , success, context, appContext); + if (appContext.container().configuration().mode() != Mode.offline) + generateAccounting(caller, callerQualifier, callerIp == null ? UNKNOWN : callerIp, success, context, + appContext); - long durationInMillis = System.currentTimeMillis()-startCallThreadLocal.get(); + long durationInMillis = System.currentTimeMillis() - startCallThreadLocal.get(); - Metrics.globalRegistry.timer("http.requests", "response",Integer.toString(e.response().getStatus()) - , "context", context, "result", success?"SUCCEDED":"FAILED", "caller-ip", callerIp, - "caller-username", caller, "service-class", appContext.configuration().serviceClass(), "service-name", appContext.configuration().name(), - "method", InnerMethodName.instance.get()).record(durationInMillis, TimeUnit.MILLISECONDS); - - log.info("REQUEST SERVED ON {}:{}({}) CALLED FROM {}@{} IN SCOPE {} {}(CODE {}) IN {} millis", - appContext.configuration().name(),appContext.configuration().serviceClass(), InnerMethodName.instance.get(), - caller, callerIp, context, success?"SUCCEDED":"FAILED", e.response().getStatus(),durationInMillis); + /* + * Metrics.globalRegistry.timer("smartgears.requests", + * "response",Integer.toString(e.response().getStatus()) , "context", context, + * "result", success?"SUCCEDED":"FAILED", "caller-ip", callerIp, + * "caller-username", caller, "service-class", + * appContext.configuration().serviceClass(), "service-name", + * appContext.configuration().name(), "method", + * InnerMethodName.instance.get()).record(durationInMillis, + * TimeUnit.MILLISECONDS); + */ + log.info("REQUEST SERVED ON {}:{}({}) CALLED FROM {}@{} IN SCOPE {} {}(CODE {}) IN {} millis", + appContext.configuration().name(), appContext.configuration().serviceClass(), + InnerMethodName.instance.get(), caller, callerIp, context, success ? "SUCCEDED" : "FAILED", + e.response().getStatus(), durationInMillis); - }catch (Exception e1) { - log.error("error on accounting",e); + } catch (Exception e1) { + log.error("error on accounting", e); throw e1; } finally { startCallThreadLocal.remove(); @@ -100,11 +104,13 @@ public class RequestAccounting extends RequestHandler { } - void generateAccounting(String caller, String callerQualifier, String remoteHost, boolean success, String gcubeContext, ApplicationContext appContext){ - AccountingPersistenceFactory.setFallbackLocation(appContext.container().configuration().accountingFallbackLocation()); + void generateAccounting(String caller, String callerQualifier, String remoteHost, boolean success, + String gcubeContext, ApplicationContext appContext) { + AccountingPersistenceFactory + .setFallbackLocation(appContext.container().configuration().accountingFallbackLocation()); AccountingPersistence persistence = AccountingPersistenceFactory.getPersistence(); ServiceUsageRecord serviceUsageRecord = new ServiceUsageRecord(); - try{ + try { serviceUsageRecord.setConsumerId(caller); serviceUsageRecord.setCallerQualifier(callerQualifier); @@ -112,21 +118,22 @@ public class RequestAccounting extends RequestHandler { serviceUsageRecord.setServiceClass(appContext.configuration().serviceClass()); serviceUsageRecord.setServiceName(appContext.configuration().name()); - serviceUsageRecord.setHost(appContext.container().configuration().hostname()+":"+appContext.container().configuration().port()); + serviceUsageRecord.setHost(appContext.container().configuration().hostname() + ":" + + appContext.container().configuration().port()); serviceUsageRecord.setCalledMethod(InnerMethodName.instance.get()); serviceUsageRecord.setCallerHost(remoteHost); - serviceUsageRecord.setOperationResult(success?OperationResult.SUCCESS:OperationResult.FAILED); - serviceUsageRecord.setDuration(System.currentTimeMillis()-startCallThreadLocal.get()); + serviceUsageRecord.setOperationResult(success ? OperationResult.SUCCESS : OperationResult.FAILED); + serviceUsageRecord.setDuration(System.currentTimeMillis() - startCallThreadLocal.get()); persistence.account(serviceUsageRecord); - }catch(Exception ex){ - log.warn("invalid record passed to accounting ",ex); + } catch (Exception ex) { + log.warn("invalid record passed to accounting ", ex); } } private String getContext(ApplicationContext appContext) { String infrastructure = appContext.container().configuration().infrastructure(); - String context= "/"+infrastructure; + String context = "/" + infrastructure; if (SecretManagerProvider.instance.get() != null) context = SecretManagerProvider.instance.get().getContext(); return context; @@ -137,6 +144,4 @@ public class RequestAccounting extends RequestHandler { return getName(); } - - } diff --git a/src/main/java/org/gcube/smartgears/handlers/application/request/RequestMetrics.java b/src/main/java/org/gcube/smartgears/handlers/application/request/RequestMetrics.java new file mode 100644 index 0000000..719a173 --- /dev/null +++ b/src/main/java/org/gcube/smartgears/handlers/application/request/RequestMetrics.java @@ -0,0 +1,48 @@ +package org.gcube.smartgears.handlers.application.request; + +import java.time.Duration; + +import org.gcube.smartgears.Constants; +import org.gcube.smartgears.handlers.application.RequestEvent; +import org.gcube.smartgears.handlers.application.RequestHandler; +import org.gcube.smartgears.handlers.application.ResponseEvent; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import io.micrometer.core.instrument.Metrics; + +public class RequestMetrics extends RequestHandler { + + private static Logger log = LoggerFactory.getLogger(RequestMetrics.class); + + private static ThreadLocal startCallThreadLocal = new ThreadLocal(); + + private static final String HTTP_REQUEST_METRICS_NAME = "http.server.requests"; + + @Override + public String getName() { + return Constants.request_metrics; + } + + @Override + public boolean isUnfiltrable() { + return true; + } + + @Override + public void handleRequest(RequestEvent e) { + startCallThreadLocal.set(System.currentTimeMillis()); + } + + @Override + public void handleResponse(ResponseEvent e) { + String statusCode = Integer.toString(e.response().getStatus()); + Metrics.globalRegistry.timer(HTTP_REQUEST_METRICS_NAME, "status", statusCode).record(Duration.ofMillis(System.currentTimeMillis() - startCallThreadLocal.get())); + Metrics.globalRegistry.counter(HTTP_REQUEST_METRICS_NAME, "status", statusCode); + startCallThreadLocal.remove(); + log.debug("metrics for current call saved"); + } + + + +} diff --git a/src/main/java/org/gcube/smartgears/managers/RequestManager.java b/src/main/java/org/gcube/smartgears/managers/RequestManager.java index 11cf66c..d1f2dec 100644 --- a/src/main/java/org/gcube/smartgears/managers/RequestManager.java +++ b/src/main/java/org/gcube/smartgears/managers/RequestManager.java @@ -8,6 +8,7 @@ import java.io.IOException; import java.util.ArrayList; import java.util.Collections; import java.util.List; +import java.util.stream.Collectors; import javax.servlet.Filter; import javax.servlet.FilterChain; @@ -139,19 +140,18 @@ public class RequestManager implements Filter { for (Exclude exclude : context.configuration().excludes()){ String excludePath= exclude.getPath(); log.trace("exclude is {}",exclude); - if ( - (WILDCARD).equals(excludePath) || + if ((WILDCARD).equals(excludePath) || (excludePath.endsWith(WILDCARD) && path!=null && path.startsWith(excludePath.substring(0,excludePath.length()-2))) || excludePath.equals(path) || (path.endsWith("/") && excludePath.equals(path.substring(0, path.length()-1))) ){ - //ALL handler are filtered - if (exclude.getHandlers().isEmpty()) return Collections.emptyList(); + //ALL handler are filtered except for unfiltrable + if (exclude.getHandlers().isEmpty()) return handlersToFilter.stream().filter(RequestHandler::isUnfiltrable).toList(); List filteredHandlers = new ArrayList<>(); - for (RequestHandler rh : handlersToFilter){ - if (!exclude.getHandlers().contains(rh.getName())) + for (RequestHandler rh : handlersToFilter) + if (rh.isUnfiltrable() || !exclude.getHandlers().contains(rh.getName())) filteredHandlers.add(rh); - } + return filteredHandlers; } } @@ -168,10 +168,10 @@ public class RequestManager implements Filter { if (include.getHandlers().isEmpty()) return handlersToFilter; List filteredHandlers = new ArrayList<>(); - for (RequestHandler rh : handlersToFilter){ - if (include.getHandlers().contains(rh.getName())) + for (RequestHandler rh : handlersToFilter) + if (rh.isUnfiltrable() || include.getHandlers().contains(rh.getName())) filteredHandlers.add(rh); - } + return filteredHandlers; } } @@ -213,37 +213,6 @@ public class RequestManager implements Filter { } - // helpers - /* - private boolean shouldExcludeRequest(HttpServletRequest request) { - - String query = request.getQueryString(); - - log.debug("servletPath is {} and pathInfo is {}",request.getServletPath(), request.getPathInfo()); - - if ("wsdl".equals(query) || "wsdl=1".equals(query)) - return true; - - String path = request.getServletPath()==null?"":request.getServletPath(); - - path += request.getPathInfo() ==null?"":request.getPathInfo(); - - - log.debug("check if should exclude call with path {}", path); - - for (Exclude exclude : context.configuration().excludes()){ - if (!exclude.getHandlers().isEmpty()) continue; - String excludePath= exclude.getPath(); - log.trace("exclude is {}",exclude); - if ( - (EXCLUDE_ALL).equals(exclude) || - (excludePath.endsWith(EXCLUDE_ALL) && path!=null && path.startsWith(excludePath.substring(0,excludePath.length()-2))) || - excludePath.equals(path) || (path.endsWith("/") && excludePath.equals(path.substring(0, path.length()-1))) - ) - return true; - } - return false; - }*/ private void handleError(HttpServletRequest request, HttpServletResponse response,Throwable t) throws IOException {