From 215ba8a8db46505ad7a2adfccd4d0da352ddb458 Mon Sep 17 00:00:00 2001 From: Marcin Grzejszczak Date: Thu, 11 Oct 2018 15:38:21 +0200 Subject: [PATCH] Logs everywhere --- .../instrument/reactor/ReactorSleuth.java | 11 ++++------- .../reactor/ScopePassingSpanSubscriber.java | 7 +++++-- .../reactor/SpanSubscriptionProvider.java | 2 +- .../reactor/TraceReactorAutoConfiguration.java | 3 +++ .../sleuth/instrument/web/TraceWebFilter.java | 2 +- .../SleuthSpanCreatorAspectWebFluxTests.java | 8 +++----- .../reactor/Issue866Configuration.java | 6 ++++++ ...rAutoConfigurationAccessorConfiguration.java | 17 ----------------- .../instrument/web/TraceWebFluxTests.java | 10 ++-------- 9 files changed, 25 insertions(+), 41 deletions(-) diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ReactorSleuth.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ReactorSleuth.java index 273725abf..1643cd1a7 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ReactorSleuth.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ReactorSleuth.java @@ -47,12 +47,6 @@ public abstract class ReactorSleuth { private ReactorSleuth() { } - private static SpanSubscriptionProvider spanSubscriptionProvider( - BeanFactory beanFactory, Scannable scannable, CoreSubscriber sub) { - return new SpanSubscriptionProvider(beanFactory, sub, sub.currentContext(), - scannable.name()); - } - /** * Return a span operator pointcut given a {@link Tracing}. This can be used in * reactor via {@link reactor.core.publisher.Flux#transform(Function)}, @@ -67,6 +61,9 @@ public abstract class ReactorSleuth { @SuppressWarnings("unchecked") public static Function, ? extends Publisher> scopePassingSpanOperator( ConfigurableApplicationContext beanFactory) { + if (log.isTraceEnabled()) { + log.trace("Scope passing operator [" + beanFactory + "]"); + } return (sourcePub -> { // TODO: Remove this once Reactor 3.1.8 is released // do the checks directly on actual original Publisher @@ -94,7 +91,7 @@ public abstract class ReactorSleuth { } if (log.isTraceEnabled()) { log.trace( - "Spring Context is not yet refreshed, falling back to lazy span subscriber. Reactor Context is [" + "Spring Context [" + beanFactory + "] is not yet refreshed, falling back to lazy span subscriber. Reactor Context is [" + sub.currentContext() + "] and name is [" + scannable.name() + "]"); } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ScopePassingSpanSubscriber.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ScopePassingSpanSubscriber.java index c7c7e3e10..fb349bac1 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ScopePassingSpanSubscriber.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/ScopePassingSpanSubscriber.java @@ -34,8 +34,7 @@ import reactor.util.context.Context; * @author Marcin Grzejszczak * @since 2.0.0 */ -final class ScopePassingSpanSubscriber extends AtomicBoolean - implements SpanSubscription { +final class ScopePassingSpanSubscriber implements SpanSubscription { private static final Log log = LogFactory.getLog(ScopePassingSpanSubscriber.class); @@ -111,4 +110,8 @@ final class ScopePassingSpanSubscriber extends AtomicBoolean return this.context; } + private void clearSpan() { + this.tracer.withSpanInScope(null); + } + } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/SpanSubscriptionProvider.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/SpanSubscriptionProvider.java index 8705e7c0b..5fb1773bc 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/SpanSubscriptionProvider.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/SpanSubscriptionProvider.java @@ -52,7 +52,7 @@ class SpanSubscriptionProvider implements Supplier> { this.context = context; this.name = name; if (log.isTraceEnabled()) { - log.trace("Context [" + context + "], name [" + name + "]"); + log.trace("Spring context [" + beanFactory + "], Reactor context [" + context + "], name [" + name + "]"); } } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfiguration.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfiguration.java index bf70c699f..3b3bea264 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfiguration.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfiguration.java @@ -72,6 +72,9 @@ public class TraceReactorAutoConfiguration { @ConditionalOnMissingBean static HookRegisteringBeanDefinitionRegistryPostProcessor traceHookRegisteringBeanDefinitionRegistryPostProcessor( ConfigurableApplicationContext context) { + if (log.isTraceEnabled()) { + log.trace("Registering bean definition registry post processor for context [" + context + "]"); + } return new HookRegisteringBeanDefinitionRegistryPostProcessor(context); } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFilter.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFilter.java index a67627843..7f73e3274 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFilter.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFilter.java @@ -131,7 +131,7 @@ public final class TraceWebFilter implements WebFilter, Ordered { @Override public Mono filter(ServerWebExchange exchange, WebFilterChain chain) { - if (tracer().currentSpan() != null) { + if (tracer().currentSpan() != null) { // clear any previous trace tracer().withSpanInScope(null); } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/annotation/SleuthSpanCreatorAspectWebFluxTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/annotation/SleuthSpanCreatorAspectWebFluxTests.java index 5f797e8a2..3daa256bf 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/annotation/SleuthSpanCreatorAspectWebFluxTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/annotation/SleuthSpanCreatorAspectWebFluxTests.java @@ -41,7 +41,6 @@ import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.actuate.trace.http.HttpTrace; import org.springframework.boot.actuate.trace.http.HttpTraceRepository; import org.springframework.boot.autoconfigure.EnableAutoConfiguration; -import org.springframework.boot.autoconfigure.ImportAutoConfiguration; import org.springframework.boot.test.context.SpringBootTest; import org.springframework.boot.web.server.LocalServerPort; import org.springframework.cloud.sleuth.DisableWebFluxSecurity; @@ -61,7 +60,8 @@ import static org.assertj.core.api.BDDAssertions.then; @RunWith(SpringRunner.class) @SpringBootTest(properties = { "spring.main.web-application-type=reactive" }, classes = { SleuthSpanCreatorAspectWebFluxTests.TestEndpoint.class, - SleuthSpanCreatorAspectWebFluxTests.TestConfiguration.class }, webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT) + SleuthSpanCreatorAspectWebFluxTests.TestConfiguration.class }, + webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT) @DirtiesContext public class SleuthSpanCreatorAspectWebFluxTests { @@ -85,7 +85,6 @@ public class SleuthSpanCreatorAspectWebFluxTests { @AfterClass @BeforeClass public static void cleanup() { - System.out.println("DUPA2"); Hooks.resetOnLastOperator(); TraceReactorAutoConfigurationAccessorConfiguration.close(); } @@ -100,7 +99,7 @@ public class SleuthSpanCreatorAspectWebFluxTests { this.reporter.clear(); this.repository.clear(); log.info("Running app on port [" + this.port + "]"); - this.webClient = WebTestClient.bindToServer().baseUrl("http://localhost:" + port) + this.webClient = WebTestClient.bindToServer().baseUrl("http://localhost:" + this.port) .build(); } @@ -233,7 +232,6 @@ public class SleuthSpanCreatorAspectWebFluxTests { @Configuration @EnableAutoConfiguration @DisableWebFluxSecurity - @ImportAutoConfiguration(TraceReactorAutoConfigurationAccessorConfiguration.class) protected static class TestConfiguration { @Bean diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/Issue866Configuration.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/Issue866Configuration.java index ff27ca43c..de0a0906f 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/Issue866Configuration.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/Issue866Configuration.java @@ -16,6 +16,9 @@ package org.springframework.cloud.sleuth.instrument.reactor; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; + import org.springframework.beans.BeansException; import org.springframework.beans.factory.config.ConfigurableListableBeanFactory; import org.springframework.context.ConfigurableApplicationContext; @@ -28,6 +31,8 @@ import org.springframework.context.annotation.Configuration; @Configuration public class Issue866Configuration { + private static final Log log = LogFactory.getLog(Issue866Configuration.class); + // we don't want to force direct dependencies between components // because Spring might just properly setup the context // we want to ensure that the HRBDRPP is always executed before @@ -37,6 +42,7 @@ public class Issue866Configuration { @Bean HookRegisteringBeanDefinitionRegistryPostProcessor overridingProcessorForTests( ConfigurableApplicationContext context) { + log.info("Registering a HookRegisteringBeanDefinitionRegistryPostProcessor for context [" + context + "]"); TestHook hook = new TestHook(context); Issue866Configuration.hook = hook; return hook; diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfigurationAccessorConfiguration.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfigurationAccessorConfiguration.java index 628c9df97..9e43884d4 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfigurationAccessorConfiguration.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/reactor/TraceReactorAutoConfigurationAccessorConfiguration.java @@ -5,17 +5,9 @@ import org.apache.commons.logging.LogFactory; import reactor.core.publisher.Hooks; import reactor.core.scheduler.Schedulers; -import org.springframework.boot.autoconfigure.AutoConfigureBefore; -import org.springframework.boot.autoconfigure.condition.ConditionalOnMissingBean; -import org.springframework.context.ConfigurableApplicationContext; -import org.springframework.context.annotation.Bean; -import org.springframework.context.annotation.Configuration; - /** * @author Marcin Grzejszczak */ -@Configuration -@AutoConfigureBefore(TraceReactorAutoConfiguration.class) public class TraceReactorAutoConfigurationAccessorConfiguration { private static final Log log = LogFactory @@ -31,13 +23,4 @@ public class TraceReactorAutoConfigurationAccessorConfiguration { Schedulers.resetFactory(); } - @Bean - static HookRegisteringBeanDefinitionRegistryPostProcessor testTraceHookRegisteringBeanDefinitionRegistryPostProcessor( - ConfigurableApplicationContext context) { - log.info("Running clean up and creating the post processor"); - close(); - return TraceReactorAutoConfiguration.TraceReactorConfiguration - .traceHookRegisteringBeanDefinitionRegistryPostProcessor(context); - } - } \ No newline at end of file diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFluxTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFluxTests.java index 0ee53325e..4769e3f74 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFluxTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceWebFluxTests.java @@ -56,16 +56,10 @@ public class TraceWebFluxTests { public static final String EXPECTED_TRACE_ID = "b919095138aa4c6e"; - @BeforeClass - @AfterClass - public static void setup() { - Hooks.resetOnLastOperator(); - TraceReactorAutoConfigurationAccessorConfiguration.close(); - } - @Test public void should_instrument_web_filter() throws Exception { // setup + TraceReactorAutoConfigurationAccessorConfiguration.close(); ConfigurableApplicationContext context = new SpringApplicationBuilder( TraceWebFluxTests.Config.class) .web(WebApplicationType.REACTIVE) @@ -105,6 +99,7 @@ public class TraceWebFluxTests { // cleanup context.close(); + TraceReactorAutoConfigurationAccessorConfiguration.close(); } private void clean(ArrayListSpanReporter accumulator, Controller2 controller2) { @@ -173,7 +168,6 @@ public class TraceWebFluxTests { @Configuration @EnableAutoConfiguration(exclude = { TraceWebClientAutoConfiguration.class }) @DisableWebFluxSecurity - @ImportAutoConfiguration(TraceReactorAutoConfigurationAccessorConfiguration.class) static class Config { @Bean