Examples with W3TraceContext io.datarouter.instrumentation.trace.W3TraceContext used on opensource projects

Example 1 with W3TraceContext

use of io.datarouter.instrumentation.trace.W3TraceContext in project datarouter by hotpads.

the class DatarouterHttpClientIoExceptionCircuitBreaker method call.

public DatarouterHttpResponse call(CloseableHttpClient httpClient, DatarouterHttpRequest request, Consumer<HttpEntity> httpEntityConsumer, HttpClientContext context, Supplier<Boolean> enableBreakers, Supplier<Boolean> traceInQueryString, Supplier<Boolean> debugLog) throws DatarouterHttpException {
    CircuitBreakerState state = getState();
    if (state == CircuitBreakerState.OPEN && enableBreakers.get()) {
        incrementCounterOnStateChange("open");
        throw new DatarouterHttpCircuitBreakerException(name, callResultQueue.getOriginalException());
    }
    DatarouterHttpException ex;
    TracerTool.startSpan("http call " + request.getPath(), TraceSpanGroupType.HTTP);
    Tracer tracer = TracerThreadLocal.get();
    W3TraceContext traceContext;
    if (tracer != null && tracer.getTraceContext().isPresent()) {
        traceContext = tracer.getTraceContext().get().copy();
        traceContext.updateParentIdAndAddTracestateMember();
    } else {
        count("traceContext null");
        traceContext = new W3TraceContext(Trace2Dto.getCurrentTimeInNs());
    }
    String traceparent = traceContext.getTraceparent().toString();
    if (traceInQueryString.get()) {
        request.addGetParam(TRACEPARENT, traceparent);
    }
    HttpRequestBase internalHttpRequest = request.getRequest();
    count("request");
    logger.debug("traceparent={} passing to request={}", traceparent, request.getPath());
    internalHttpRequest.addHeader(TRACEPARENT, traceparent);
    internalHttpRequest.addHeader(TRACESTATE, traceContext.getTracestate().toString());
    context.setAttribute(TRACEPARENT, traceContext.getTraceparent().toString());
    if (debugLog.get()) {
        logger.warn("sending http request method={} url={}", internalHttpRequest.getMethod(), internalHttpRequest.getURI());
    }
    long requestStartTimeNs = Trace2Dto.getCurrentTimeInNs();
    try {
        HttpResponse httpResponse = httpClient.execute(internalHttpRequest, context);
        Duration duration = Duration.ofNanos(Trace2Dto.getCurrentTimeInNs() - requestStartTimeNs);
        String entity = null;
        int statusCode = httpResponse.getStatusLine().getStatusCode();
        count("response " + statusCode);
        boolean isBadStatusCode = statusCode >= HttpStatus.SC_BAD_REQUEST;
        HttpEntity httpEntity = httpResponse.getEntity();
        if (httpEntity != null) {
            // skip the httpEntityConsumer in case of error because we are going to close the input stream
            if (httpEntityConsumer != null && !isBadStatusCode) {
                httpEntityConsumer.accept(httpEntity);
            } else {
                entity = EntityUtils.toString(httpEntity);
            }
        }
        Optional<Traceparent> remoteTraceparent = Optional.ofNullable(httpResponse.getFirstHeader(TRACEPARENT)).map(Header::getValue).map(Traceparent::parse).filter(Optional::isPresent).map(Optional::get);
        remoteTraceparent.ifPresent(tp -> TracerTool.appendToSpanInfo("remote parentId", tp.parentId));
        if (remoteTraceparent.isPresent() && remoteTraceparent.get().shouldSample()) {
            // if remote server has forced sample for trace, we also force sample the client's trace
            TracerTool.setForceSample();
        }
        if (duration.compareTo(LOG_SLOW_REQUEST_THRESHOLD) > 0) {
            logger.warn("Slow request target={} durationS={} remoteTraceparent={}", request.getPath(), duration.getSeconds(), remoteTraceparent.orElse(null));
        }
        DatarouterHttpResponse response = new DatarouterHttpResponse(httpResponse, context, statusCode, entity);
        if (isBadStatusCode) {
            TracerTool.appendToSpanInfo("bad status code", statusCode);
            ex = new DatarouterHttpResponseException(response, duration, traceparent, request.getPath());
            callResultQueue.insertFalseResultWithException(ex);
            // no need to abort the connection, we received a response line, the connection is probably still good
            response.tryClose();
            throw ex;
        }
        if (state == CircuitBreakerState.HALF_OPEN) {
            callResultQueue.reset();
            incrementCounterOnStateChange("closing");
            logger.error("Half opened circuit now closing. CircuitName={}", name);
        }
        callResultQueue.insertTrueResult();
        return response;
    } catch (IOException e) {
        count("IOException");
        TracerTool.appendToSpanInfo("exception", e.getMessage());
        ex = new DatarouterHttpConnectionAbortedException(e, TimeUnit.NANOSECONDS.toMillis(requestStartTimeNs), traceparent, request.getPath());
        callResultQueue.insertFalseResultWithException(ex);
    } catch (CancellationException e) {
        count("CancellationException");
        TracerTool.appendToSpanInfo("exception", e.getMessage());
        ex = new DatarouterHttpRequestInterruptedException(e, TimeUnit.NANOSECONDS.toMillis(requestStartTimeNs), traceparent, request.getPath());
        callResultQueue.insertFalseResultWithException(ex);
    } finally {
        TracerTool.finishSpan();
    }
    // connection might have gone bad, destroying it
    if (internalHttpRequest != null) {
        forceAbortRequestUnchecked(internalHttpRequest);
    }
    throw ex;
}

Example 2 with W3TraceContext

use of io.datarouter.instrumentation.trace.W3TraceContext in project datarouter by hotpads.

the class TraceFilter method doFilter.

@Override
public void doFilter(ServletRequest req, ServletResponse res, FilterChain fc) throws IOException, ServletException {
    try {
        HttpServletRequest request = (HttpServletRequest) req;
        HttpServletResponse response = (HttpServletResponse) res;
        // get or create TraceContext
        Long traceCreated = Trace2Dto.getCurrentTimeInNs();
        String traceparentStr = request.getHeader(DatarouterHttpClientIoExceptionCircuitBreaker.TRACEPARENT);
        String tracestateStr = request.getHeader(DatarouterHttpClientIoExceptionCircuitBreaker.TRACESTATE);
        W3TraceContext traceContext = new W3TraceContext(traceparentStr, tracestateStr, traceCreated);
        String initialParentId = traceContext.getTraceparent().parentId;
        traceContext.updateParentIdAndAddTracestateMember();
        RequestAttributeTool.set(request, BaseHandler.TRACE_URL_REQUEST_ATTRIBUTE, urlBuilder.buildTraceForCurrentServer(traceContext.getTraceId(), traceContext.getParentId()));
        RequestAttributeTool.set(request, BaseHandler.TRACE_CONTEXT, traceContext.copy());
        // traceflag might be incorrect because it might have been modified during request processing
        if (traceSettings.addTraceparentHeader.get()) {
            response.setHeader(DatarouterHttpClientIoExceptionCircuitBreaker.TRACEPARENT, traceContext.getTraceparent().toString());
        }
        // bind these to all threads, even if tracing is disabled
        Tracer tracer = new DatarouterTracer(serverName.get(), null, traceContext);
        tracer.setSaveThreadCpuTime(traceSettings.saveThreadCpuTime.get());
        tracer.setSaveThreadMemoryAllocated(traceSettings.saveThreadMemoryAllocated.get());
        tracer.setSaveSpanCpuTime(traceSettings.saveSpanCpuTime.get());
        tracer.setSaveSpanMemoryAllocated(traceSettings.saveSpanMemoryAllocated.get());
        TracerThreadLocal.bindToThread(tracer);
        String requestThreadName = (request.getContextPath() + " request").trim();
        tracer.createAndStartThread(requestThreadName, Trace2Dto.getCurrentTimeInNs());
        Long threadId = Thread.currentThread().getId();
        boolean saveCpuTime = traceSettings.saveTraceCpuTime.get();
        Long cpuTimeBegin = saveCpuTime ? MxBeans.THREAD.getCurrentThreadCpuTime() : null;
        boolean saveAllocatedBytes = traceSettings.saveTraceAllocatedBytes.get();
        Long threadAllocatedBytesBegin = saveAllocatedBytes ? MxBeans.THREAD.getThreadAllocatedBytes(threadId) : null;
        boolean errored = false;
        try {
            fc.doFilter(req, res);
        } catch (Exception e) {
            errored = true;
            throw e;
        } finally {
            long ended = Trace2Dto.getCurrentTimeInNs();
            Long cpuTimeEnded = saveCpuTime ? MxBeans.THREAD.getCurrentThreadCpuTime() : null;
            Long threadAllocatedBytesEnded = saveAllocatedBytes ? MxBeans.THREAD.getThreadAllocatedBytes(threadId) : null;
            Traceparent traceparent = tracer.getTraceContext().get().getTraceparent();
            Trace2ThreadDto rootThread = null;
            if (tracer.getCurrentThreadId() != null) {
                rootThread = ((DatarouterTracer) tracer).getCurrentThread();
                rootThread.setCpuTimeEndedNs(cpuTimeEnded);
                rootThread.setMemoryAllocatedBytesEnded(threadAllocatedBytesEnded);
                rootThread.setEnded(ended);
                ((DatarouterTracer) tracer).setCurrentThread(null);
            }
            Trace2Dto trace2 = new Trace2Dto(traceparent, initialParentId, request.getContextPath(), request.getRequestURI().toString(), request.getQueryString(), traceCreated, ended, serviceName.get(), tracer.getDiscardedThreadCount(), tracer.getThreadQueue().size(), cpuTimeBegin, cpuTimeEnded, threadAllocatedBytesBegin, threadAllocatedBytesEnded);
            Long traceDurationMs = trace2.getDurationInMs();
            Long cpuTime = saveCpuTime ? TimeUnit.NANOSECONDS.toMillis(cpuTimeEnded - cpuTimeBegin) : null;
            Long threadAllocatedKB = saveAllocatedBytes ? (threadAllocatedBytesEnded - threadAllocatedBytesBegin) / 1024 : null;
            String saveReason = null;
            if (traceSettings.saveTraces.get()) {
                if (traceDurationMs > traceSettings.saveTracesOverMs.get()) {
                    saveReason = "duration";
                }
                if (RequestTool.getBoolean(request, "trace", false)) {
                    saveReason = "queryParam";
                }
                if (tracer.shouldSample()) {
                    saveReason = "traceContext";
                }
                if (errored) {
                    saveReason = "error";
                }
            }
            if (saveReason != null) {
                Counters.inc("traceSaved " + saveReason);
                List<Trace2ThreadDto> threads = new ArrayList<>(tracer.getThreadQueue());
                List<Trace2SpanDto> spans = new ArrayList<>(tracer.getSpanQueue());
                if (rootThread != null) {
                    rootThread.setTotalSpanCount(spans.size());
                    // force to save the rootThread even though the queue could be full
                    threads.add(rootThread);
                }
                String userAgent = RequestTool.getUserAgent(request);
                String userToken = currentSessionInfo.getSession(request).map(Session::getUserToken).orElse("unknown");
                HttpRequestRecordDto httpRequestRecord = buildHttpRequestRecord(errored, request, traceCreated, userToken, traceparent);
                String destination = offerTrace2(new Trace2BundleDto(trace2, threads, spans), httpRequestRecord);
                logger.warn("Trace saved to={} traceparent={} initialParentId={} durationMs={}" + " cpuTimeMs={} threadAllocatedKB={} path={} query={} userAgent=\"{}\" userToken={}", destination, traceparent, initialParentId, traceDurationMs, cpuTime, threadAllocatedKB, trace2.type, trace2.params, userAgent, userToken);
            } else if (traceDurationMs > traceSettings.logTracesOverMs.get() || TracerTool.shouldLog()) {
                // only log once
                logger.warn("Trace logged durationMs={} cpuTimeMs={} threadAllocatedKB={} path={}" + " query={}, traceparent={}", traceDurationMs, cpuTime, threadAllocatedKB, trace2.type, trace2.params, traceparent);
            }
            Optional<Class<? extends BaseHandler>> handlerClassOpt = RequestAttributeTool.get(request, BaseHandler.HANDLER_CLASS);
            Optional<Method> handlerMethodOpt = RequestAttributeTool.get(request, BaseHandler.HANDLER_METHOD);
            if (handlerClassOpt.isPresent() && handlerMethodOpt.isPresent()) {
                Class<? extends BaseHandler> handlerClass = handlerClassOpt.get();
                if (traceSettings.latencyRecordedHandlers.get().contains(handlerClass.getName())) {
                    handlerMetrics.saveMethodLatency(handlerClass, handlerMethodOpt.get(), traceDurationMs);
                }
            }
        }
    } finally {
        TracerThreadLocal.clearFromThread();
    }
}