@Override public void spanCompleted(Span span) { try { zipkin2.Span zipkinSpan = zipkinSpanConverter.convertWingtipsSpanToZipkinSpan(span, zipkinEndpoint); zipkinSpanReporter.report(zipkinSpan); } catch(Throwable ex) { long currentBadSpanCount = spanHandlingErrorCounter.incrementAndGet(); // Only log once every MIN_SPAN_HANDLING_ERROR_LOG_INTERVAL_MILLIS time interval to prevent log spam from a malicious (or broken) caller. long currentTimeMillis = System.currentTimeMillis(); long timeSinceLastLogMsgMillis = currentTimeMillis - lastSpanHandlingErrorLogTimeEpochMillis; if (timeSinceLastLogMsgMillis >= MIN_SPAN_HANDLING_ERROR_LOG_INTERVAL_MILLIS) { // We're not synchronizing the read and write to lastSpanHandlingErrorLogTimeEpochMillis, and that's ok. If we get a few extra // log messages due to a race condition it's not the end of the world - we're still satisfying the goal of not allowing a // malicious caller to endlessly spam the logs. lastSpanHandlingErrorLogTimeEpochMillis = currentTimeMillis; zipkinConversionOrReportingErrorLogger.warn( "There have been {} spans that were not Zipkin compatible, or that experienced an error during span handling. Latest example: " + "wingtips_span_with_error=\"{}\", conversion_or_handling_error=\"{}\"", currentBadSpanCount, span.toKeyValueString(), ex.toString()); } } } }
@Override public void spanCompleted(Span span) { try { zipkin2.Span zipkinSpan = zipkinSpanConverter.convertWingtipsSpanToZipkinSpan(span, zipkinEndpoint); zipkinSpanReporter.report(zipkinSpan); } catch(Throwable ex) { long currentBadSpanCount = spanHandlingErrorCounter.incrementAndGet(); // Only log once every MIN_SPAN_HANDLING_ERROR_LOG_INTERVAL_MILLIS time interval to prevent log spam from a malicious (or broken) caller. long currentTimeMillis = System.currentTimeMillis(); long timeSinceLastLogMsgMillis = currentTimeMillis - lastSpanHandlingErrorLogTimeEpochMillis; if (timeSinceLastLogMsgMillis >= MIN_SPAN_HANDLING_ERROR_LOG_INTERVAL_MILLIS) { // We're not synchronizing the read and write to lastSpanHandlingErrorLogTimeEpochMillis, and that's ok. If we get a few extra // log messages due to a race condition it's not the end of the world - we're still satisfying the goal of not allowing a // malicious caller to endlessly spam the logs. lastSpanHandlingErrorLogTimeEpochMillis = currentTimeMillis; zipkinConversionOrReportingErrorLogger.warn( "There have been {} spans that were not Zipkin compatible, or that experienced an error during span handling. Latest example: " + "wingtips_span_with_error=\"{}\", conversion_or_handling_error=\"{}\"", currentBadSpanCount, span.toKeyValueString(), ex.toString()); } } } }
@Test public void spanCompleted_does_not_propagate_exceptions_generated_by_span_converter() { // given doThrow(new RuntimeException("kaboom")).when(spanConverterMock).convertWingtipsSpanToZipkinSpan(any(Span.class), any(Endpoint.class)); // when Throwable ex = catchThrowable(() -> listener.spanCompleted(spanMock)); // then verify(spanConverterMock).convertWingtipsSpanToZipkinSpan(spanMock, listener.zipkinEndpoint); verifyZeroInteractions(spanReporterMock); assertThat(ex).isNull(); }
@Test public void spanCompleted_converts_to_zipkin_span_and_passes_it_to_zipkinSpanReporter() { // given zipkin2.Span zipkinSpan = zipkin2.Span.newBuilder().traceId("42").id("4242").name("foo").build(); doReturn(zipkinSpan).when(spanConverterMock).convertWingtipsSpanToZipkinSpan(any(Span.class), any(Endpoint.class)); // when listener.spanCompleted(spanMock); // then verify(spanConverterMock).convertWingtipsSpanToZipkinSpan(spanMock, listener.zipkinEndpoint); verify(spanReporterMock).report(zipkinSpan); }