Skip to content

Commit

Permalink
Add deadline timeout for automatic transactions (#2865)
Browse files Browse the repository at this point in the history
* Add deadline timeout for automatic transactions

* Update Changelog

* Address PR comments

* Fix formatting

* Add missing test, improve naming

* Ensure deadline timeout is only set once
  • Loading branch information
markushi authored Aug 8, 2023
1 parent 8e78ac3 commit 0b3de21
Show file tree
Hide file tree
Showing 11 changed files with 267 additions and 50 deletions.
2 changes: 2 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,8 @@ Breaking changes:
- Set ip_address to {{auto}} by default, even if sendDefaultPII is disabled ([#2860](https://github.com/getsentry/sentry-java/pull/2860))
- Instead use the "Prevent Storing of IP Addresses" option in the "Security & Privacy" project settings on sentry.io
- Reduce timeout of AsyncHttpTransport to avoid ANR ([#2879](https://github.com/getsentry/sentry-java/pull/2879))
- Add deadline timeout for automatic transactions ([#2865](https://github.com/getsentry/sentry-java/pull/2865))
- This affects all automatically generated transactions on Android (UI, clicks), the default timeout is 30s

### Fixes

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -192,6 +192,9 @@ private void startTracing(final @NotNull Activity activity) {
final Boolean coldStart = AppStartState.getInstance().isColdStart();

final TransactionOptions transactionOptions = new TransactionOptions();
transactionOptions.setDeadlineTimeout(
TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION);

if (options.isEnableActivityLifecycleTracingAutoFinish()) {
transactionOptions.setIdleTimeout(options.getIdleTimeout());
transactionOptions.setTrimEnd(true);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -237,6 +237,8 @@ private void startTracing(final @NotNull UiElement target, final @NotNull String

final TransactionOptions transactionOptions = new TransactionOptions();
transactionOptions.setWaitForChildren(true);
transactionOptions.setDeadlineTimeout(
TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION);
transactionOptions.setIdleTimeout(options.getIdleTimeout());
transactionOptions.setTrimEnd(true);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -43,7 +43,6 @@ import org.mockito.kotlin.clearInvocations
import org.mockito.kotlin.eq
import org.mockito.kotlin.mock
import org.mockito.kotlin.never
import org.mockito.kotlin.times
import org.mockito.kotlin.verify
import org.mockito.kotlin.whenever
import org.robolectric.Shadows.shadowOf
Expand Down Expand Up @@ -354,7 +353,7 @@ class ActivityLifecycleIntegrationTest {
}

@Test
fun `Transaction op is ui_load`() {
fun `Transaction op is ui_load and idle+deadline timeouts are set`() {
val sut = fixture.getSut()
fixture.options.tracesSampleRate = 1.0
sut.register(fixture.hub, fixture.options)
Expand All @@ -365,11 +364,14 @@ class ActivityLifecycleIntegrationTest {
sut.onActivityCreated(activity, fixture.bundle)

verify(fixture.hub).startTransaction(
check {
check<TransactionContext> {
assertEquals("ui.load", it.operation)
assertEquals(TransactionNameSource.COMPONENT, it.transactionNameSource)
},
any<TransactionOptions>()
check<TransactionOptions> { transactionOptions ->
assertEquals(fixture.options.idleTimeout, transactionOptions.idleTimeout)
assertEquals(TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION, transactionOptions.deadlineTimeout)
}
)
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -206,6 +206,24 @@ class SentryGestureListenerTracingTest {
)
}

@Test
fun `captures transaction and both idle+deadline timeouts are set`() {
val sut = fixture.getSut<View>()

sut.onSingleTapUp(fixture.event)

verify(fixture.hub).startTransaction(
any<TransactionContext>(),
check<TransactionOptions> { transactionOptions ->
assertEquals(fixture.options.idleTimeout, transactionOptions.idleTimeout)
assertEquals(
TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION,
transactionOptions.deadlineTimeout
)
}
)
}

@Test
fun `captures transaction with interaction event type as op`() {
val sut = fixture.getSut<View>()
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -132,15 +132,16 @@ class SentryNavigationListener @JvmOverloads constructor(
// we add '/' to the name to match dart and web pattern
name = "/" + name.substringBefore('/') // strip out arguments from the tx name

val transactonOptions = TransactionOptions().also {
val transactionOptions = TransactionOptions().also {
it.isWaitForChildren = true
it.idleTimeout = hub.options.idleTimeout
it.deadlineTimeout = TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION
it.isTrimEnd = true
}

val transaction = hub.startTransaction(
TransactionContext(name, TransactionNameSource.ROUTE, NAVIGATION_OP),
transactonOptions
transactionOptions
)

transaction.spanContext.origin = traceOriginAppendix?.let {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,12 @@ class SentryNavigationListenerTest {
whenever(context.resources).thenReturn(resources)
whenever(navController.context).thenReturn(context)
whenever(destination.route).thenReturn(toRoute)
return SentryNavigationListener(hub, enableBreadcrumbs, enableTracing, traceOriginAppendix)
return SentryNavigationListener(
hub,
enableBreadcrumbs,
enableTracing,
traceOriginAppendix
)
}
}

Expand Down Expand Up @@ -355,7 +360,8 @@ class SentryNavigationListenerTest {
fun `starts new trace if performance is disabled`() {
val sut = fixture.getSut(enableTracing = false)

val argumentCaptor: ArgumentCaptor<ScopeCallback> = ArgumentCaptor.forClass(ScopeCallback::class.java)
val argumentCaptor: ArgumentCaptor<ScopeCallback> =
ArgumentCaptor.forClass(ScopeCallback::class.java)
val scope = Scope(fixture.options)
val propagationContextAtStart = scope.propagationContext
whenever(fixture.hub.configureScope(argumentCaptor.capture())).thenAnswer {
Expand Down Expand Up @@ -385,4 +391,18 @@ class SentryNavigationListenerTest {

assertEquals("auto.navigation.jetpack_compose", fixture.transaction.spanContext.origin)
}

@Test
fun `Navigation listener transactions set automatic deadline timeout`() {
val sut = fixture.getSut()

sut.onDestinationChanged(fixture.navController, fixture.destination, null)

verify(fixture.hub).startTransaction(
any<TransactionContext>(),
check<TransactionOptions> { options ->
assertEquals(TransactionOptions.DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION, options.deadlineTimeout)
}
)
}
}
3 changes: 3 additions & 0 deletions sentry/api/sentry.api
Original file line number Diff line number Diff line change
Expand Up @@ -2352,15 +2352,18 @@ public abstract interface class io/sentry/TransactionFinishedCallback {
}

public final class io/sentry/TransactionOptions : io/sentry/SpanOptions {
public static final field DEFAULT_DEADLINE_TIMEOUT_AUTO_TRANSACTION J
public fun <init> ()V
public fun getCustomSamplingContext ()Lio/sentry/CustomSamplingContext;
public fun getDeadlineTimeout ()Ljava/lang/Long;
public fun getIdleTimeout ()Ljava/lang/Long;
public fun getStartTimestamp ()Lio/sentry/SentryDate;
public fun getTransactionFinishedCallback ()Lio/sentry/TransactionFinishedCallback;
public fun isBindToScope ()Z
public fun isWaitForChildren ()Z
public fun setBindToScope (Z)V
public fun setCustomSamplingContext (Lio/sentry/CustomSamplingContext;)V
public fun setDeadlineTimeout (Ljava/lang/Long;)V
public fun setIdleTimeout (Ljava/lang/Long;)V
public fun setStartTimestamp (Lio/sentry/SentryDate;)V
public fun setTransactionFinishedCallback (Lio/sentry/TransactionFinishedCallback;)V
Expand Down
139 changes: 106 additions & 33 deletions sentry/src/main/java/io/sentry/SentryTracer.java
Original file line number Diff line number Diff line change
Expand Up @@ -37,10 +37,14 @@ public final class SentryTracer implements ITransaction {
*/
private @NotNull FinishStatus finishStatus = FinishStatus.NOT_FINISHED;

private volatile @Nullable TimerTask timerTask;
private volatile @Nullable TimerTask idleTimeoutTask;
private volatile @Nullable TimerTask deadlineTimeoutTask;

private volatile @Nullable Timer timer = null;
private final @NotNull Object timerLock = new Object();
private final @NotNull AtomicBoolean isFinishTimerRunning = new AtomicBoolean(false);

private final @NotNull AtomicBoolean isIdleFinishTimerRunning = new AtomicBoolean(false);
private final @NotNull AtomicBoolean isDeadlineTimerRunning = new AtomicBoolean(false);

private final @NotNull Baggage baggage;
private @NotNull TransactionNameSource transactionNameSource;
Expand Down Expand Up @@ -92,43 +96,59 @@ public SentryTracer(
transactionPerformanceCollector.start(this);
}

if (transactionOptions.getIdleTimeout() != null) {
if (transactionOptions.getIdleTimeout() != null
|| transactionOptions.getDeadlineTimeout() != null) {
timer = new Timer(true);

scheduleDeadlineTimeout();
scheduleFinish();
}
}

@Override
public void scheduleFinish() {
synchronized (timerLock) {
cancelTimer();
if (timer != null) {
isFinishTimerRunning.set(true);
timerTask =
new TimerTask() {
@Override
public void run() {
finishFromTimer();
}
};

try {
timer.schedule(timerTask, transactionOptions.getIdleTimeout());
} catch (Throwable e) {
hub.getOptions()
.getLogger()
.log(SentryLevel.WARNING, "Failed to schedule finish timer", e);
// if we failed to schedule the finish timer for some reason, we finish it here right away
finishFromTimer();
final @Nullable Long idleTimeout = transactionOptions.getIdleTimeout();

if (idleTimeout != null) {
cancelIdleTimer();
isIdleFinishTimerRunning.set(true);
idleTimeoutTask =
new TimerTask() {
@Override
public void run() {
onIdleTimeoutReached();
}
};

try {
timer.schedule(idleTimeoutTask, idleTimeout);
} catch (Throwable e) {
hub.getOptions()
.getLogger()
.log(SentryLevel.WARNING, "Failed to schedule finish timer", e);
// if we failed to schedule the finish timer for some reason, we finish it here right
// away
onIdleTimeoutReached();
}
}
}
}
}

private void finishFromTimer() {
final SpanStatus status = getStatus();
private void onIdleTimeoutReached() {
final @Nullable SpanStatus status = getStatus();
finish((status != null) ? status : SpanStatus.OK);
isFinishTimerRunning.set(false);
isIdleFinishTimerRunning.set(false);
}

private void onDeadlineTimeoutReached() {
final @Nullable SpanStatus status = getStatus();
forceFinish(
(status != null) ? status : SpanStatus.DEADLINE_EXCEEDED,
transactionOptions.getIdleTimeout() != null);
isDeadlineTimerRunning.set(false);
}

@Override
Expand Down Expand Up @@ -222,6 +242,8 @@ public void finish(
if (timer != null) {
synchronized (timerLock) {
if (timer != null) {
cancelIdleTimer();
cancelDeadlineTimer();
timer.cancel();
timer = null;
}
Expand All @@ -244,12 +266,51 @@ public void finish(
}
}

private void cancelTimer() {
private void cancelIdleTimer() {
synchronized (timerLock) {
if (timerTask != null) {
timerTask.cancel();
isFinishTimerRunning.set(false);
timerTask = null;
if (idleTimeoutTask != null) {
idleTimeoutTask.cancel();
isIdleFinishTimerRunning.set(false);
idleTimeoutTask = null;
}
}
}

private void scheduleDeadlineTimeout() {
final @Nullable Long deadlineTimeOut = transactionOptions.getDeadlineTimeout();
if (deadlineTimeOut != null) {
synchronized (timerLock) {
if (timer != null) {
cancelDeadlineTimer();
isDeadlineTimerRunning.set(true);
deadlineTimeoutTask =
new TimerTask() {
@Override
public void run() {
onDeadlineTimeoutReached();
}
};
try {
timer.schedule(deadlineTimeoutTask, deadlineTimeOut);
} catch (Throwable e) {
hub.getOptions()
.getLogger()
.log(SentryLevel.WARNING, "Failed to schedule finish timer", e);
// if we failed to schedule the finish timer for some reason, we finish it here right
// away
onDeadlineTimeoutReached();
}
}
}
}
}

private void cancelDeadlineTimer() {
synchronized (timerLock) {
if (deadlineTimeoutTask != null) {
deadlineTimeoutTask.cancel();
isDeadlineTimerRunning.set(false);
deadlineTimeoutTask = null;
}
}
}
Expand Down Expand Up @@ -360,7 +421,7 @@ private ISpan createChild(

Objects.requireNonNull(parentSpanId, "parentSpanId is required");
Objects.requireNonNull(operation, "operation is required");
cancelTimer();
cancelIdleTimer();
final Span span =
new Span(
root.getTraceId(),
Expand Down Expand Up @@ -720,8 +781,14 @@ Span getRoot() {

@TestOnly
@Nullable
TimerTask getTimerTask() {
return timerTask;
TimerTask getIdleTimeoutTask() {
return idleTimeoutTask;
}

@TestOnly
@Nullable
TimerTask getDeadlineTimeoutTask() {
return deadlineTimeoutTask;
}

@TestOnly
Expand All @@ -733,7 +800,13 @@ Timer getTimer() {
@TestOnly
@NotNull
AtomicBoolean isFinishTimerRunning() {
return isFinishTimerRunning;
return isIdleFinishTimerRunning;
}

@TestOnly
@NotNull
AtomicBoolean isDeadlineTimerRunning() {
return isDeadlineTimerRunning;
}

@TestOnly
Expand Down
Loading

0 comments on commit 0b3de21

Please sign in to comment.