From 63a0a116826c76c10ecdfdc2cf8c8066f20037d8 Mon Sep 17 00:00:00 2001 From: Anton Duyun Date: Wed, 26 Apr 2023 16:17:39 +0300 Subject: [PATCH] Telemetry polishing (#138) --- .../java/ru/tinkoff/kora/common/Context.java | 6 ++- .../common/telemetry/DataBaseLogger.java | 2 + .../telemetry/DefaultDataBaseLogger.java | 5 +++ .../telemetry/DefaultDataBaseTelemetry.java | 18 +++++++-- .../telemetry/DefaultGrpcServerTelemetry.java | 33 ++++++++++++++-- .../kora/grpc/telemetry/GrpcServerLogger.java | 2 + .../grpc/telemetry/Slf4jGrpcServerLogger.java | 5 +++ .../interceptor/TelemetryInterceptor.java | 12 ++++-- .../telemetry/DefaultHttpClientTelemetry.java | 38 ++++++++++++++----- .../common/telemetry/HttpClientTelemetry.java | 2 + .../telemetry/DefaultHttpServerTelemetry.java | 34 ++++++++++++----- .../common/telemetry/HttpServerLogger.java | 7 ++++ .../DefaultSoapClientTelemetryFactory.java | 19 +++++++++- .../DefaultJmsConsumerTelemetry.java | 18 +++++++-- .../kora/jms/telemetry/JmsConsumerLogger.java | 2 + 15 files changed, 165 insertions(+), 38 deletions(-) diff --git a/common/src/main/java/ru/tinkoff/kora/common/Context.java b/common/src/main/java/ru/tinkoff/kora/common/Context.java index 6b896bd10..2470e8746 100644 --- a/common/src/main/java/ru/tinkoff/kora/common/Context.java +++ b/common/src/main/java/ru/tinkoff/kora/common/Context.java @@ -50,8 +50,10 @@ public void inject() { INSTANCE.set(this); } - public static void clear() { - INSTANCE.remove(); + public static Context clear() { + var clean = new Context(); + INSTANCE.set(clean); + return clean; } public T set(Key key, T value) { diff --git a/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DataBaseLogger.java b/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DataBaseLogger.java index 648b62cb4..1459878f0 100644 --- a/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DataBaseLogger.java +++ b/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DataBaseLogger.java @@ -5,6 +5,8 @@ import javax.annotation.Nullable; public interface DataBaseLogger { + boolean isEnabled(); + void logQueryBegin(QueryContext queryContext); void logQueryEnd(long duration, QueryContext queryContext, @Nullable Throwable ex); diff --git a/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseLogger.java b/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseLogger.java index 1839c7042..1bb526137 100644 --- a/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseLogger.java +++ b/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseLogger.java @@ -17,6 +17,11 @@ public DefaultDataBaseLogger(String poolName) { this.queryLog = LoggerFactory.getLogger("ru.tinkoff.kora.database.jdbc." + poolName + ".query"); } + @Override + public boolean isEnabled() { + return this.queryLog.isDebugEnabled(); + } + @Override public void logQueryBegin(QueryContext queryContext) { if (this.queryLog.isDebugEnabled()) { diff --git a/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseTelemetry.java b/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseTelemetry.java index 67a49749e..82eed2aa1 100644 --- a/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseTelemetry.java +++ b/database/database-common/src/main/java/ru/tinkoff/kora/database/common/telemetry/DefaultDataBaseTelemetry.java @@ -6,6 +6,9 @@ import javax.annotation.Nullable; public class DefaultDataBaseTelemetry implements DataBaseTelemetry { + private static final DataBaseTelemetryContext NOOP_CTX = exception -> { + }; + @Nullable private final DataBaseMetricWriter metricWriter; @Nullable @@ -29,14 +32,21 @@ public Object getMetricRegistry() { @Override public DataBaseTelemetryContext createContext(Context ctx, QueryContext query) { - var span = this.tracing == null ? null : this.tracing.createQuerySpan(ctx, query); + var metricWriter = this.metricWriter; + var tracing = this.tracing; + var logger = this.logger; + if (metricWriter == null && tracing == null && (logger == null || !logger.isEnabled())) { + return NOOP_CTX; + } + + var span = tracing == null ? null : tracing.createQuerySpan(ctx, query); var start = System.nanoTime(); - if (this.logger != null) this.logger.logQueryBegin(query); + if (logger != null) logger.logQueryBegin(query); return exception -> { var duration = System.nanoTime() - start; - if (this.metricWriter != null) this.metricWriter.recordQuery(start, query, exception); - if (this.logger != null) this.logger.logQueryEnd(duration, query, exception); + if (metricWriter != null) metricWriter.recordQuery(start, query, exception); + if (logger != null) logger.logQueryEnd(duration, query, exception); if (span != null) span.close(exception); }; } diff --git a/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/DefaultGrpcServerTelemetry.java b/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/DefaultGrpcServerTelemetry.java index 5b6b4c051..dc749a35c 100644 --- a/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/DefaultGrpcServerTelemetry.java +++ b/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/DefaultGrpcServerTelemetry.java @@ -2,10 +2,28 @@ import io.grpc.Metadata; import io.grpc.ServerCall; +import io.grpc.Status; import javax.annotation.Nullable; public final class DefaultGrpcServerTelemetry implements GrpcServerTelemetry { + private static final GrpcServerTelemetryContext NOOP_CTX = new GrpcServerTelemetryContext() { + @Override + public void close(Status status, Throwable exception) { + + } + + @Override + public void sendMessage(Object message) { + + } + + @Override + public void receiveMessage(Object message) { + + } + }; + @Nullable private final GrpcServerMetricsFactory metrics; @Nullable @@ -21,13 +39,20 @@ public DefaultGrpcServerTelemetry(@Nullable GrpcServerMetricsFactory metrics, @N @Override public GrpcServerTelemetryContext createContext(ServerCall call, Metadata headers) { + var metrics = this.metrics; + var tracing = this.tracing; + var logger = this.logger; + if (metrics == null && tracing == null && (logger == null || !logger.isEnabled())) { + return DefaultGrpcServerTelemetry.NOOP_CTX; + } + var start = System.nanoTime(); var serviceName = service(call); var methodName = method(call); - var metrics = this.metrics == null ? null : this.metrics.get(call, headers, serviceName, methodName); - var span = this.tracing == null ? null : this.tracing.createSpan(call, headers, serviceName, methodName); - if (this.logger != null) this.logger.logBegin(call, headers, serviceName, methodName); - return new DefaultGrpcServerTelemetryContext(start, serviceName, methodName, metrics, logger, span); + var m = metrics == null ? null : metrics.get(call, headers, serviceName, methodName); + var span = tracing == null ? null : tracing.createSpan(call, headers, serviceName, methodName); + if (logger != null) logger.logBegin(call, headers, serviceName, methodName); + return new DefaultGrpcServerTelemetryContext(start, serviceName, methodName, m, logger, span); } private String service(ServerCall call) { diff --git a/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/GrpcServerLogger.java b/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/GrpcServerLogger.java index 3dd27cb8a..a7716ee6c 100644 --- a/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/GrpcServerLogger.java +++ b/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/GrpcServerLogger.java @@ -8,6 +8,8 @@ public interface GrpcServerLogger { + boolean isEnabled(); + void logEnd(String serviceName, String methodName, @Nullable Status status, @Nullable Throwable exception, long processingTime); void logBegin(ServerCall call, Metadata headers, String serviceName, String methodName); diff --git a/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/Slf4jGrpcServerLogger.java b/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/Slf4jGrpcServerLogger.java index 5cce63658..4ff41ce98 100644 --- a/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/Slf4jGrpcServerLogger.java +++ b/grpc/src/main/java/ru/tinkoff/kora/grpc/telemetry/Slf4jGrpcServerLogger.java @@ -13,6 +13,11 @@ public final class Slf4jGrpcServerLogger implements GrpcServerLogger { private static final Logger log = LoggerFactory.getLogger(GrpcServer.class); + @Override + public boolean isEnabled() { + return log.isWarnEnabled(); + } + @Override public void logEnd(String serviceName, String methodName, @Nullable Status status, @Nullable Throwable exception, long processingTime) { if (status != null && status.isOk()) { diff --git a/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/interceptor/TelemetryInterceptor.java b/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/interceptor/TelemetryInterceptor.java index 4b63ed65a..eff70d985 100644 --- a/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/interceptor/TelemetryInterceptor.java +++ b/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/interceptor/TelemetryInterceptor.java @@ -17,14 +17,18 @@ public TelemetryInterceptor(HttpClientTelemetry telemetry) { @Override public Mono processRequest(Function> chain, HttpClientRequest request) { + if (!this.telemetry.isEnabled()) { + return chain.apply(request); + } + return Mono.deferContextual(rctx -> { var ctx = Context.Reactor.current(rctx).fork(); ctx.inject(); - var applyResult = this.telemetry.get(ctx, request); + var telemetryContext = this.telemetry.get(ctx, request); - return chain.apply(applyResult.request()) - .doOnError(e -> applyResult.close(null, e)) - .map(response -> applyResult.close(response, null)) + return chain.apply(telemetryContext.request()) + .doOnError(e -> telemetryContext.close(null, e)) + .map(response -> telemetryContext.close(response, null)) .contextWrite(c -> Context.Reactor.inject(c, ctx)); }); } diff --git a/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/DefaultHttpClientTelemetry.java b/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/DefaultHttpClientTelemetry.java index 97239b332..43b6fb5df 100644 --- a/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/DefaultHttpClientTelemetry.java +++ b/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/DefaultHttpClientTelemetry.java @@ -35,7 +35,22 @@ public DefaultHttpClientTelemetry(@Nullable HttpClientTracer tracing, @Nullable } @Override + public boolean isEnabled() { + return metrics != null + || tracing != null + || logger != null && (logger.logRequest() || logger.logResponse()); + } + + @Override + @Nullable public HttpServerTelemetryContext get(Context ctx, HttpClientRequest request) { + var logger = this.logger; + var tracing = this.tracing; + var metrics = this.metrics; + if (metrics == null && tracing == null && (logger == null || (!logger.logRequest() && !logger.logResponse()))) { + return null; + } + var startTime = System.nanoTime(); var method = request.method(); var uri = URI.create(request.resolvedUri()); @@ -46,22 +61,22 @@ public HttpServerTelemetryContext get(Context ctx, HttpClientRequest request) { var resolvedUri = request.resolvedUri(); var target = operation.substring(method.length() + 1); - var createSpanResult = this.tracing == null ? null : this.tracing.createSpan(ctx, request); + var createSpanResult = tracing == null ? null : tracing.createSpan(ctx, request); if (createSpanResult != null) { request = createSpanResult.request(); } var headers = request.headers(); - if (this.logger != null && this.logger.logRequest()) { - if (!this.logger.logRequestHeaders()) { - this.logger.logRequest(authority, request.method(), operation, resolvedUri, null, null); + if (logger != null && logger.logRequest()) { + if (!logger.logRequestHeaders()) { + logger.logRequest(authority, request.method(), operation, resolvedUri, null, null); } else { - if (!this.logger.logRequestBody()) { - this.logger.logRequest(authority, request.method(), operation, resolvedUri, request.headers(), null); + if (!logger.logRequestBody()) { + logger.logRequest(authority, request.method(), operation, resolvedUri, headers, null); } else { var requestBodyCharset = this.detectCharset(request.headers()); if (requestBodyCharset == null) { - this.logger.logRequest(authority, request.method(), operation, resolvedUri, request.headers(), null); + this.logger.logRequest(authority, request.method(), operation, resolvedUri, headers, null); } else { var requestBodyFlux = this.wrapBody(request.body(), true, l -> { var s = byteBufListToBodyString(l, requestBodyCharset); @@ -116,13 +131,16 @@ public HttpClientResponse close(@Nullable HttpClientResponse response, @Nullable }, () -> bodySubscribed.set(true)); return new HttpClientResponse.Default( - response.code(), response.headers(), responseBodyFlux, Mono.defer(() -> { + response.code(), + response.headers(), + responseBodyFlux, + Mono.defer(() -> { if (bodySubscribed.compareAndSet(false, true)) { responseBodyFlux.subscribe(); } return response.close(); - } - )); + }) + ); } }; } diff --git a/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/HttpClientTelemetry.java b/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/HttpClientTelemetry.java index 6c9b02b0c..b56f38425 100644 --- a/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/HttpClientTelemetry.java +++ b/http/http-client-common/src/main/java/ru/tinkoff/kora/http/client/common/telemetry/HttpClientTelemetry.java @@ -14,5 +14,7 @@ interface HttpServerTelemetryContext { HttpClientResponse close(@Nullable HttpClientResponse response, @Nullable Throwable exception); } + boolean isEnabled(); + HttpServerTelemetryContext get(Context ctx, HttpClientRequest request); } diff --git a/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/DefaultHttpServerTelemetry.java b/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/DefaultHttpServerTelemetry.java index 900d270e3..cacf3fd67 100644 --- a/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/DefaultHttpServerTelemetry.java +++ b/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/DefaultHttpServerTelemetry.java @@ -6,6 +6,9 @@ public final class DefaultHttpServerTelemetry implements HttpServerTelemetry { private static final String UNMATCHED_ROUTE_TEMPLATE = "UNKNOWN_ROUTE"; + private static final HttpServerTelemetryContext NOOP_CTX = (statusCode, resultCode, exception) -> { + + }; @Nullable private final HttpServerMetrics metrics; @@ -22,21 +25,31 @@ public DefaultHttpServerTelemetry(@Nullable HttpServerMetrics metrics, @Nullable @Override public HttpServerTelemetryContext get(PublicApiHandler.PublicApiRequest request, @Nullable String routeTemplate) { + var metrics = this.metrics; + var logger = this.logger; + var tracer = this.tracer; + if (metrics == null && tracer == null && (logger == null || !logger.isEnabled())) { + return NOOP_CTX; + } var start = System.nanoTime(); var method = request.method(); var scheme = request.scheme(); var host = request.hostName(); - if (this.metrics != null) this.metrics.requestStarted(method, routeTemplate != null ? routeTemplate : UNMATCHED_ROUTE_TEMPLATE, host, scheme); + if (metrics != null) metrics.requestStarted(method, routeTemplate != null ? routeTemplate : UNMATCHED_ROUTE_TEMPLATE, host, scheme); final HttpServerTracer.HttpServerSpan span; final String operation; if (routeTemplate != null) { operation = method + " " + routeTemplate; - span = this.tracer != null - ? this.tracer.createSpan(routeTemplate, request) - : null; - if (this.logger != null) this.logger.logStart(operation); + if (tracer != null) { + span = tracer.createSpan(routeTemplate, request); + } else { + span = null; + } + if (logger != null) { + logger.logStart(operation); + } } else { span = null; operation = null; @@ -46,12 +59,15 @@ public HttpServerTelemetryContext get(PublicApiHandler.PublicApiRequest request, var end = System.nanoTime(); var processingTime = end - start; - if (this.metrics != null) this.metrics.requestFinished(method, routeTemplate != null ? routeTemplate : UNMATCHED_ROUTE_TEMPLATE, host, scheme, statusCode, processingTime); + if (metrics != null) metrics.requestFinished(method, routeTemplate != null ? routeTemplate : UNMATCHED_ROUTE_TEMPLATE, host, scheme, statusCode, processingTime); if (routeTemplate != null) { - if (this.logger != null) this.logger.logEnd(operation, statusCode, resultCode, processingTime, exception); - - if (span != null) span.close(statusCode, resultCode, exception); + if (logger != null) { + logger.logEnd(operation, statusCode, resultCode, processingTime, exception); + } + if (span != null) { + span.close(statusCode, resultCode, exception); + } } }; } diff --git a/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/HttpServerLogger.java b/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/HttpServerLogger.java index 66153e5dc..f07d70c97 100644 --- a/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/HttpServerLogger.java +++ b/http/http-server-common/src/main/java/ru/tinkoff/kora/http/server/common/telemetry/HttpServerLogger.java @@ -12,11 +12,18 @@ public interface HttpServerLogger { Logger log = LoggerFactory.getLogger(HttpServer.class); + boolean isEnabled(); + void logStart(String operation); void logEnd(String operation, Integer statusCode, HttpResultCode resultCode, long processingTime, @Nullable Throwable exception); final class DefaultHttpServerLogger implements HttpServerLogger { + @Override + public boolean isEnabled() { + return log.isInfoEnabled(); + } + @Override public void logStart(String operation) { if (!log.isInfoEnabled()) { diff --git a/http/soap-client/src/main/java/ru/tinkoff/kora/soap/client/common/telemetry/DefaultSoapClientTelemetryFactory.java b/http/soap-client/src/main/java/ru/tinkoff/kora/soap/client/common/telemetry/DefaultSoapClientTelemetryFactory.java index 7f6e7374a..5160e035f 100644 --- a/http/soap-client/src/main/java/ru/tinkoff/kora/soap/client/common/telemetry/DefaultSoapClientTelemetryFactory.java +++ b/http/soap-client/src/main/java/ru/tinkoff/kora/soap/client/common/telemetry/DefaultSoapClientTelemetryFactory.java @@ -1,8 +1,22 @@ package ru.tinkoff.kora.soap.client.common.telemetry; +import ru.tinkoff.kora.soap.client.common.SoapResult; + import javax.annotation.Nullable; public class DefaultSoapClientTelemetryFactory implements SoapClientTelemetryFactory { + private static final SoapClientTelemetry.SoapTelemetryContext NOOP_CTX = new SoapClientTelemetry.SoapTelemetryContext() { + @Override + public void success(SoapResult.Success result) { + + } + + @Override + public void failure(SoapClientFailure failure) { + + } + }; + @Nullable private final SoapClientMetricsFactory metricsFactory; @@ -12,7 +26,10 @@ public DefaultSoapClientTelemetryFactory(@Nullable SoapClientMetricsFactory metr @Override public SoapClientTelemetry get(String serviceName, String soapMethod, String url) { - var metrics = this.metricsFactory == null ? null : this.metricsFactory.get(serviceName, soapMethod, url); + if (this.metricsFactory == null) { + return envelope -> NOOP_CTX; + } + var metrics = this.metricsFactory.get(serviceName, soapMethod, url); return requestEnvelope -> new DefaultSoapTelemetryContext(metrics); } } diff --git a/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/DefaultJmsConsumerTelemetry.java b/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/DefaultJmsConsumerTelemetry.java index c20dab304..a4a220857 100644 --- a/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/DefaultJmsConsumerTelemetry.java +++ b/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/DefaultJmsConsumerTelemetry.java @@ -5,6 +5,9 @@ import javax.jms.Message; public final class DefaultJmsConsumerTelemetry implements JmsConsumerTelemetry { + private static final JmsConsumerTelemetryContext NOOP_CTX = e -> { + + }; @Nullable private final JmsConsumerTracer tracing; @Nullable @@ -20,13 +23,20 @@ public DefaultJmsConsumerTelemetry(@Nullable JmsConsumerTracer tracing, @Nullabl @Override public JmsConsumerTelemetryContext get(Message message) throws JMSException { + var tracing = this.tracing; + var metrics = this.metrics; + var logger = this.logger; + if (tracing == null && metrics == null && (logger == null || !logger.isEnabled())) { + return DefaultJmsConsumerTelemetry.NOOP_CTX; + } + var start = System.nanoTime(); - var span = this.tracing == null ? null : this.tracing.get(message); - if (this.logger != null) this.logger.onMessageReceived(message); + var span = tracing == null ? null : tracing.get(message); + if (logger != null) logger.onMessageReceived(message); return e -> { var duration = System.nanoTime() - start; - if (this.logger != null) this.logger.onMessageProcessed(message, duration); - if (this.metrics != null) this.metrics.onMessageProcessed(message, duration); + if (logger != null) logger.onMessageProcessed(message, duration); + if (metrics != null) metrics.onMessageProcessed(message, duration); if (span != null) span.close(e); }; } diff --git a/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/JmsConsumerLogger.java b/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/JmsConsumerLogger.java index 1f1c9575c..3f1104243 100644 --- a/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/JmsConsumerLogger.java +++ b/jms/src/main/java/ru/tinkoff/kora/jms/telemetry/JmsConsumerLogger.java @@ -6,4 +6,6 @@ public interface JmsConsumerLogger { void onMessageReceived(Message message); void onMessageProcessed(Message message, long duration); + + boolean isEnabled(); }