Closes the scope for transaction managers; fixes gh-2082

This commit is contained in:
Marcin Grzejszczak
2022-02-02 13:15:03 +01:00
parent e4c5f50a1d
commit 57c076c28c
7 changed files with 48 additions and 20 deletions

View File

@@ -70,7 +70,7 @@ public class TracePlatformTransactionManager implements PlatformTransactionManag
try {
TransactionDefinition def = (definition != null ? definition : TransactionDefinition.withDefaults());
TransactionStatus status = this.delegate.getTransaction(definition);
span = taggedSpan(currentSpan, span, def, status);
taggedSpan(currentSpan, span, def, status);
return status;
}
catch (Exception e) {
@@ -127,7 +127,7 @@ public class TracePlatformTransactionManager implements PlatformTransactionManag
}
finally {
SleuthTxSpan.TX_SPAN.wrap(span).event(SleuthTxSpan.Events.COMMIT);
span.end();
spanAndScope.close();
if (ex == null) {
if (log.isDebugEnabled()) {
log.debug("No exception was found - will clear thread local span");
@@ -160,7 +160,7 @@ public class TracePlatformTransactionManager implements PlatformTransactionManag
}
finally {
SleuthTxSpan.TX_SPAN.wrap(span).event(SleuthTxSpan.Events.ROLLBACK);
span.end();
spanAndScope.close();
this.threadLocalSpan.remove();
}
}

View File

@@ -74,6 +74,9 @@ public class TraceReactiveTransactionManager implements ReactiveTransactionManag
return Mono.deferContextual(contextView -> this.delegate.getReactiveTransaction(definition).map(tx -> {
Span span = SleuthTxSpan.TX_SPAN.wrap(span(contextView));
if (tx.isNewTransaction() || span == null) {
if (log.isDebugEnabled()) {
log.debug("New transaction is required");
}
if (span == null) {
span = SleuthTxSpan.TX_SPAN.wrap(tracer().nextSpan()).name(SleuthTxSpan.TX_SPAN.getName()).start();
}
@@ -82,9 +85,14 @@ public class TraceReactiveTransactionManager implements ReactiveTransactionManag
.start();
}
TracePlatformTransactionManagerTags.tag(span, definition, this.delegate.getClass());
} else if (log.isDebugEnabled()) {
log.debug("Will continue the transaction for span [" + span + "]");
}
Tracer.SpanInScope withSpan = tracer().withSpan(span);
SpanAndScope spanAndScope = new SpanAndScope(span, withSpan);
if (log.isDebugEnabled()) {
log.debug("Got transaction for span [" + spanAndScope + "]");
}
return new TraceReactiveTransaction(tx, spanAndScope);
}));
}
@@ -122,14 +130,13 @@ public class TraceReactiveTransactionManager implements ReactiveTransactionManag
TraceReactiveTransaction reactiveTransaction = (TraceReactiveTransaction) transaction;
SpanAndScope spanAndScope = reactiveTransaction.spanAndScope;
Span span = spanAndScope.getSpan();
Tracer.SpanInScope scope = spanAndScope.getScope();
if (log.isDebugEnabled()) {
log.debug("Commiting the transaction for span [" + spanAndScope + "]");
}
return this.delegate.commit(reactiveTransaction.delegate)
// TODO: Fix me when this is resolved in Reactor
// .doOnSubscribe(__ -> scope.close())
.doOnError(span::error).doOnSuccess(signalType -> {
span.end();
scope.close();
});
.doOnError(span::error).doOnSuccess(signalType -> spanAndScope.close());
}
@Override
@@ -140,16 +147,13 @@ public class TraceReactiveTransactionManager implements ReactiveTransactionManag
TraceReactiveTransaction reactiveTransaction = (TraceReactiveTransaction) transaction;
SpanAndScope spanAndScope = reactiveTransaction.spanAndScope;
Span span = spanAndScope.getSpan();
Tracer.SpanInScope scope = spanAndScope.getScope();
if (log.isDebugEnabled()) {
log.debug("Rolling back the transaction for span [" + spanAndScope + "]");
}
return this.delegate.rollback(reactiveTransaction.delegate)
// TODO: Fix me when this is resolved in Reactor
// .doOnSubscribe(__ -> scope.close())
.doOnError(span::error).doFinally(signalType -> {
span.end();
if (scope != null) {
scope.close();
}
});
.doOnError(span::error).doFinally(signalType -> spanAndScope.close());
}
static class TraceReactiveTransaction implements ReactiveTransaction {

View File

@@ -56,6 +56,8 @@ class TracePlatformTransactionManagerTests {
manager.commit(transaction);
// then
thenOneSpanWasReported(manager, span);
thenThreadLocalIsClear(manager);
then(tracer.currentSpan()).isNull();
}
@Test
@@ -74,6 +76,8 @@ class TracePlatformTransactionManagerTests {
manager.rollback(transaction);
// then
thenOneSpanWasReported(manager, span);
thenThreadLocalIsClear(manager);
then(tracer.currentSpan()).isNull();
}
@Test
@@ -97,6 +101,7 @@ class TracePlatformTransactionManagerTests {
then(firstSpan).isSameAs(manager.threadLocalSpan.get().getSpan());
manager.threadLocalSpan.remove();
thenThreadLocalIsClear(manager);
then(tracer.currentSpan()).isNull();
}
private SimpleSpan threadLocalSpan(TracePlatformTransactionManager manager) {
@@ -130,6 +135,7 @@ class TracePlatformTransactionManagerTests {
then(span.throwable).isInstanceOf(TransactionTimedOutException.class);
manager.threadLocalSpan.remove();
thenThreadLocalIsClear(manager);
then(tracer.currentSpan()).isNull();
}
@Test
@@ -144,6 +150,7 @@ class TracePlatformTransactionManagerTests {
then(span.throwable).isInstanceOf(TransactionTimedOutException.class);
manager.threadLocalSpan.remove();
thenThreadLocalIsClear(manager);
then(tracer.currentSpan()).isNull();
}
private void setupTransactionStatusWithNewTransactionStatusEqualTo(boolean transactionStatus) {

View File

@@ -41,6 +41,8 @@ public class SimpleTracer implements Tracer {
public List<SimpleSpan> spans = new ArrayList<>();
public Span currentSpan;
@Override
public Span nextSpan(Span parent) {
SimpleSpan span = nextSpan();
@@ -65,7 +67,8 @@ public class SimpleTracer implements Tracer {
@Override
public SpanInScope withSpan(Span span) {
return new NoOpSpanInScope();
this.currentSpan = span;
return () -> currentSpan = null;
}
@Override
@@ -75,10 +78,7 @@ public class SimpleTracer implements Tracer {
@Override
public Span currentSpan() {
if (this.spans.isEmpty()) {
return null;
}
return this.spans.get(spans.size() - 1);
return this.currentSpan;
}
@Override

View File

@@ -38,6 +38,7 @@ internal class AsContextElementKtTests {
fun `should return current span from context`(): Unit = runBlocking {
val simpleTracer = SimpleTracer()
val nextSpan = simpleTracer.nextSpan().start()
val inScope = simpleTracer.withSpan(nextSpan)
var spanInGlobalScopeLaunch: Span? = null
var spanInGlobalScopeAsync: Span? = null
val asContextElement = simpleTracer.asContextElement()
@@ -49,6 +50,8 @@ internal class AsContextElementKtTests {
spanInGlobalScopeAsync = coroutineContext.currentSpan()
}.await()
inScope.close();
then(spanInGlobalScopeLaunch).isSameAs(nextSpan)
then(spanInGlobalScopeAsync).isSameAs(nextSpan)
}
@@ -57,9 +60,11 @@ internal class AsContextElementKtTests {
fun `should return span from coroutine context when KotlinContextElement present`(): Unit = runBlocking {
val simpleTracer = SimpleTracer()
val nextSpan = simpleTracer.nextSpan().start()
val inScope = simpleTracer.withSpan(nextSpan)
val element = KotlinContextElement(simpleTracer)
then(element.currentSpan()).isSameAs(nextSpan)
inScope.close()
}
@Test
@@ -87,9 +92,11 @@ internal class AsContextElementKtTests {
val currentTraceContext = SimpleCurrentTraceContext()
val simpleTracer = SimpleTracer()
val nextSpan = simpleTracer.nextSpan().start()
val inScope = simpleTracer.withSpan(nextSpan)
val reactorContext = ReactorContext(Context.of(Tracer::class.java, simpleTracer, CurrentTraceContext::class.java, currentTraceContext, TraceContext::class.java, nextSpan.context()))
then(reactorContext.currentSpan()).isSameAs(nextSpan);
inScope.close()
}
@Test
@@ -97,8 +104,10 @@ internal class AsContextElementKtTests {
val simpleTracer = SimpleTracer()
val nextSpan = simpleTracer.nextSpan().start()
val reactorContext = ReactorContext(Context.of(Tracer::class.java, simpleTracer))
val inScope = simpleTracer.withSpan(nextSpan)
then(reactorContext.currentSpan()).isSameAs(nextSpan);
inScope.close()
}
@Test

View File

@@ -24,9 +24,11 @@ import org.springframework.cloud.sleuth.test.TestSpanHandler;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.test.context.ContextConfiguration;
import org.springframework.test.context.TestPropertySource;
@SpringBootTest
@ContextConfiguration(classes = R2dbcIntegrationTests.Config.class)
@TestPropertySource(properties = "logging.level.org.springframework.cloud=TRACE")
public class R2dbcIntegrationTests extends org.springframework.cloud.sleuth.instrument.r2dbc.R2dbcIntegrationTests {
@Configuration(proxyBeanMethods = false)

View File

@@ -28,6 +28,7 @@ import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.CommandLineRunner;
import org.springframework.boot.autoconfigure.EnableAutoConfiguration;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.cloud.sleuth.exporter.FinishedSpan;
import org.springframework.cloud.sleuth.test.TestSpanHandler;
import org.springframework.context.annotation.Bean;
@@ -46,6 +47,9 @@ public abstract class R2dbcIntegrationTests {
@Autowired
TestSpanHandler spans;
@Autowired
Tracer tracer;
@Test
public void should_pass_tracing_information_when_using_r2dbc() {
Set<String> traceIds = this.spans.reportedSpans().stream().map(FinishedSpan::getTraceId)
@@ -62,6 +66,8 @@ public abstract class R2dbcIntegrationTests {
.collect(Collectors.toList());
then(spanNames.stream().filter("tx"::equalsIgnoreCase).collect(Collectors.toList())).hasSize(2);
then(remoteServiceNames.stream().filter("h2"::equalsIgnoreCase).collect(Collectors.toList())).hasSize(9);
// TODO: First fix the SpanAndScope stacking
// then(tracer.currentSpan()).isNull();
}
@Configuration(proxyBeanMethods = false)