From 980e2324d7c7187b6d2a6e2fdb6a6a04a2c7dc14 Mon Sep 17 00:00:00 2001 From: Marcin Grzejszczak Date: Mon, 22 Feb 2016 12:31:19 +0100 Subject: [PATCH] [#49] Added name skip pattern for slf4j * if Span's name matches a pattern it will not be logged at all in the logs fixes #49 --- .../log/SleuthLogAutoConfiguration.java | 9 +- .../cloud/sleuth/log/Slf4jSpanListener.java | 34 ++++-- .../sleuth/log/Slf4jSpanListenerTest.java | 112 ++++++++++++++++++ 3 files changed, 147 insertions(+), 8 deletions(-) create mode 100644 spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4jSpanListenerTest.java diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/SleuthLogAutoConfiguration.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/SleuthLogAutoConfiguration.java index de338b4e9..ec4b7aa5b 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/SleuthLogAutoConfiguration.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/SleuthLogAutoConfiguration.java @@ -17,6 +17,7 @@ package org.springframework.cloud.sleuth.log; import org.slf4j.MDC; +import org.springframework.beans.factory.annotation.Value; import org.springframework.boot.autoconfigure.AutoConfigureAfter; import org.springframework.boot.autoconfigure.condition.ConditionalOnBean; import org.springframework.boot.autoconfigure.condition.ConditionalOnClass; @@ -37,11 +38,17 @@ public class SleuthLogAutoConfiguration { @Configuration @ConditionalOnClass(MDC.class) protected static class Slf4jConfiguration { + /** + * Name pattern for which span should not be printed in the logs + */ + @Value("${spring.sleuth.log.slf4j.nameSkipPattern:}") + private String nameSkipPattern; + @Bean @ConditionalOnProperty(value = "spring.sleuth.log.slf4j.enabled", matchIfMissing = true) public Slf4jSpanListener slf4jSpanStartedListener() { // Sets up MDC entries X-Trace-Id and X-Span-Id - return new Slf4jSpanListener(); + return new Slf4jSpanListener(this.nameSkipPattern); } } } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanListener.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanListener.java index 6bd581943..13079279d 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanListener.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanListener.java @@ -16,6 +16,8 @@ package org.springframework.cloud.sleuth.log; +import java.util.regex.Pattern; + import org.slf4j.Logger; import org.slf4j.MDC; import org.springframework.cloud.sleuth.Span; @@ -31,8 +33,19 @@ import org.springframework.core.annotation.Order; */ public class Slf4jSpanListener { - private static final Logger log = org.slf4j.LoggerFactory - .getLogger(Slf4jSpanListener.class); + private final Logger log; + private final Pattern nameSkipPattern; + + public Slf4jSpanListener(String nameSkipPattern) { + this.nameSkipPattern = Pattern.compile(nameSkipPattern); + this.log = org.slf4j.LoggerFactory + .getLogger(Slf4jSpanListener.class); + } + + Slf4jSpanListener(String nameSkipPattern, Logger log) { + this.nameSkipPattern = Pattern.compile(nameSkipPattern); + this.log = log; + } @EventListener(SpanAcquiredEvent.class) @Order(Ordered.LOWEST_PRECEDENCE) @@ -41,9 +54,9 @@ public class Slf4jSpanListener { MDC.put(Span.SPAN_ID_NAME, Span.idToHex(span.getSpanId())); MDC.put(Span.SPAN_EXPORT_NAME, String.valueOf(span.isExportable())); MDC.put(Span.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); - log.trace("Starting span: {}", span); + log("Starting span: {}", span); if (event.getParent() != null) { - log.trace("With parent: {}", event.getParent()); + log("With parent: {}", event.getParent()); } } @@ -54,15 +67,15 @@ public class Slf4jSpanListener { MDC.put(Span.SPAN_ID_NAME, Span.idToHex(span.getSpanId())); MDC.put(Span.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); MDC.put(Span.SPAN_EXPORT_NAME, String.valueOf(span.isExportable())); - log.trace("Continued span: {}", event.getSpan()); + log("Continued span: {}", event.getSpan()); } @EventListener(SpanReleasedEvent.class) @Order(Ordered.LOWEST_PRECEDENCE) public void stop(SpanReleasedEvent event) { - log.trace("Stopped span: {}", event.getSpan()); + log("Stopped span: {}", event.getSpan()); if (event.getParent() != null) { - log.trace("With parent: {}", event.getParent()); + log("With parent: {}", event.getParent()); MDC.put(Span.SPAN_ID_NAME, Span.idToHex(event.getParent().getSpanId())); MDC.put(Span.SPAN_EXPORT_NAME, String.valueOf(event.getParent().isExportable())); } @@ -73,4 +86,11 @@ public class Slf4jSpanListener { } } + private void log(String text, Span span) { + if (this.nameSkipPattern.matcher(span.getName()).matches()) { + return; + } + this.log.trace(text, span); + } + } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4jSpanListenerTest.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4jSpanListenerTest.java new file mode 100644 index 000000000..e79d5bae1 --- /dev/null +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4jSpanListenerTest.java @@ -0,0 +1,112 @@ +/* + * Copyright 2013-2016 the original author or authors. + * + * 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. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.springframework.cloud.sleuth.log; + +import org.junit.Test; +import org.mockito.Mockito; +import org.slf4j.Logger; +import org.springframework.cloud.sleuth.Span; +import org.springframework.cloud.sleuth.event.SpanAcquiredEvent; +import org.springframework.cloud.sleuth.event.SpanContinuedEvent; +import org.springframework.cloud.sleuth.event.SpanReleasedEvent; + +import static org.mockito.BDDMockito.then; +import static org.mockito.Matchers.anyList; +import static org.mockito.Matchers.anyString; +import static org.mockito.Mockito.never; +import static org.mockito.Mockito.times; + +/** + * @author Marcin Grzejszczak + */ +public class Slf4jSpanListenerTest { + + Span spanWithNameToBeExcluded = Span.builder().name("Hystrix").build(); + Span spanWithNameNotToBeExcluded = Span.builder().name("Aspect").build(); + String nameExcludingPattern = "^.*Hystrix.*$"; + Logger log = Mockito.mock(Logger.class); + Slf4jSpanListener slf4jSpanListener = new Slf4jSpanListener(nameExcludingPattern, log); + + @Test + public void should_log_when_start_event_arrived_and_pattern_doesnt_match_span_name() throws Exception { + slf4jSpanListener.start(new SpanAcquiredEvent(this, spanWithNameNotToBeExcluded, + spanWithNameNotToBeExcluded)); + + then(log).should(times(2)).trace(anyString(), anyList()); + } + + @Test + public void should_log_once_when_start_event_arrived_and_pattern_matches_only_parent_span_name() throws Exception { + slf4jSpanListener.start(new SpanAcquiredEvent(this, spanWithNameToBeExcluded, + spanWithNameNotToBeExcluded)); + + then(log).should().trace(anyString(), anyList()); + } + + @Test + public void should_log_when_continue_event_arrived_and_pattern_doesnt_match_span_name() throws Exception { + slf4jSpanListener.continued(new SpanContinuedEvent(this, + spanWithNameNotToBeExcluded)); + + then(log).should().trace(anyString(), anyList()); + } + + @Test + public void should_not_log_when_continue_event_arrived_and_pattern_matches_name() throws Exception { + slf4jSpanListener.continued(new SpanContinuedEvent(this, spanWithNameToBeExcluded)); + + then(log).should(never()).trace(anyString(), anyList()); + } + + @Test + public void should_log_when_close_event_arrived_and_pattern_doesnt_match_span_name() throws Exception { + slf4jSpanListener.stop(new SpanReleasedEvent(this, spanWithNameNotToBeExcluded)); + + then(log).should().trace(anyString(), anyList()); + } + + @Test + public void should_log_both_spans_when_their_names_dont_match_pattern() throws Exception { + slf4jSpanListener.stop(new SpanReleasedEvent(this, spanWithNameNotToBeExcluded, + spanWithNameNotToBeExcluded)); + + then(log).should(times(2)).trace(anyString(), anyList()); + } + + @Test + public void should_not_log_any_spans_if_both_match_pattern() throws Exception { + slf4jSpanListener.stop(new SpanReleasedEvent(this, spanWithNameToBeExcluded, + spanWithNameToBeExcluded)); + + then(log).should(never()).trace(anyString(), anyList()); + } + + @Test + public void should_log_only_current_span_if_parent_span_name_matches_pattern() throws Exception { + slf4jSpanListener.stop(new SpanReleasedEvent(this, spanWithNameNotToBeExcluded, + spanWithNameToBeExcluded)); + + then(log).should().trace(anyString(), anyList()); + } + + @Test + public void should_log_only_current_span_if_there_is_no_parent() throws Exception { + slf4jSpanListener.stop(new SpanReleasedEvent(this, spanWithNameNotToBeExcluded)); + + then(log).should().trace(anyString(), anyList()); + } +} \ No newline at end of file