Skip to content

Commit 429c0eb

Browse files
runningcodeclaude
andcommitted
revert: fix(tracing): End timed-out transactions when the timeout fell due
Reverts b9fe709 and the refinements on top of it: a timed-out transaction is stamped with the wake-up time again, as it was before. Clamping changes every reported timeout duration, and it is the whole substance of this branch rather than a byproduct of its cleanups, so it goes out as its own PR instead of riding along here. What is kept are the two cosmetics the branch picked up on the way: forceFinish's void return, and Timestamp.hashCode deferring to Long.hashCode. JAVA-642 and #5752 stay open. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
1 parent edd56b0 commit 429c0eb

5 files changed

Lines changed: 4 additions & 209 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 0 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,5 @@
11
# Changelog
22

3-
## Unreleased
4-
5-
### Fixes
6-
7-
- End a timed-out transaction at the moment its timeout fell due, rather than whenever the timer thread next gets to run. A device that slept, or froze the process, through an idle or deadline timeout used to turn an abandoned app start into a multi-hour transaction ([#6091](https://github.com/getsentry/sentry-java/pull/6091))
8-
93
## 8.56.0
104

115
### Behavioral Changes

‎sentry/api/sentry.api‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7640,7 +7640,6 @@ public final class io/sentry/time/SystemEpochClock : io/sentry/time/EpochClock {
76407640
public final class io/sentry/time/Timestamp {
76417641
public fun epochNanos ()J
76427642
public fun equals (Ljava/lang/Object;)Z
7643-
public fun getSentryDate ()Lio/sentry/SentryDate;
76447643
public fun hashCode ()I
76457644
public static fun ofEpochNanos (J)Lio/sentry/time/Timestamp;
76467645
public fun toString ()Ljava/lang/String;

‎sentry/src/main/java/io/sentry/SentryTracer.java‎

Lines changed: 3 additions & 71 deletions
Original file line numberDiff line numberDiff line change
@@ -5,8 +5,6 @@
55
import io.sentry.protocol.SentryId;
66
import io.sentry.protocol.SentryTransaction;
77
import io.sentry.protocol.TransactionNameSource;
8-
import io.sentry.time.Deadline;
9-
import io.sentry.time.Timestamp;
108
import io.sentry.util.AutoClosableReentrantLock;
119
import io.sentry.util.CollectionUtils;
1210
import io.sentry.util.Objects;
@@ -17,7 +15,6 @@
1715
import java.util.Map;
1816
import java.util.concurrent.CopyOnWriteArrayList;
1917
import java.util.concurrent.Future;
20-
import java.util.concurrent.TimeUnit;
2118
import java.util.concurrent.atomic.AtomicBoolean;
2219
import java.util.concurrent.atomic.AtomicReference;
2320
import org.jetbrains.annotations.ApiStatus;
@@ -43,10 +40,6 @@ public final class SentryTracer implements ITransaction {
4340
private volatile @Nullable Future<?> idleTimeoutFuture;
4441
private volatile @Nullable Future<?> deadlineTimeoutFuture;
4542

46-
// When each timeout falls due, captured when its timer is scheduled. See Expiry.
47-
private volatile @Nullable Expiry idleExpiry;
48-
private volatile @Nullable Expiry deadlineExpiry;
49-
5043
// Whether timeout tasks may still be scheduled. Set to false once the tracer is finished. The
5144
// executor itself is owned by the options (shared SDK-wide) and obtained from there when needed.
5245
private volatile boolean timersEnabled = false;
@@ -124,7 +117,6 @@ public void scheduleFinish() {
124117
if (idleTimeout != null) {
125118
cancelIdleTimer();
126119
isIdleFinishTimerRunning.set(true);
127-
idleExpiry = expiryIn(idleTimeout);
128120

129121
try {
130122
idleTimeoutFuture =
@@ -148,7 +140,7 @@ public void scheduleFinish() {
148140

149141
private void onIdleTimeoutReached() {
150142
final @Nullable SpanStatus status = getStatus();
151-
finish((status != null) ? status : SpanStatus.OK, finishDateOf(idleExpiry));
143+
finish((status != null) ? status : SpanStatus.OK);
152144
isIdleFinishTimerRunning.set(false);
153145
}
154146

@@ -157,77 +149,18 @@ private void onDeadlineTimeoutReached() {
157149
forceFinish(
158150
(status != null) ? status : SpanStatus.DEADLINE_EXCEEDED,
159151
transactionOptions.getIdleTimeout() != null,
160-
null,
161-
finishDateOf(deadlineExpiry));
152+
null);
162153
isDeadlineTimerRunning.set(false);
163154
}
164155

165-
/** When a timeout of {@code timeoutMillis}, scheduled now, falls due. */
166-
private @NotNull Expiry expiryIn(final long timeoutMillis) {
167-
// Yeah, we can just reach in to that scopes.options and grab whatever we want. Can't even hide
168-
// this one behind an interface.
169-
final @NotNull SentryOptions options = scopes.getOptions();
170-
return new Expiry(
171-
Deadline.after(options.getMonotonicTicker(), timeoutMillis, TimeUnit.MILLISECONDS),
172-
// This is just the current Timestamp + deadline as a wall clock time.
173-
Timestamp.ofEpochNanos(
174-
options.getEpochClock().now().epochNanos()
175-
+ TimeUnit.MILLISECONDS.toNanos(timeoutMillis)));
176-
}
177-
178-
// A little bridge between the new Timestamp API and the old SentryDate.
179-
private static @Nullable SentryDate finishDateOf(final @Nullable Expiry expiry) {
180-
// In Kotlin it would be expiry?.expiredAt()?.sentryDate if that makes it easier to read.
181-
final @Nullable Timestamp expiredAt = expiry == null ? null : expiry.expiredAt();
182-
return expiredAt == null ? null : expiredAt.getSentryDate();
183-
}
184-
185-
/**
186-
* When a timeout falls due: the instant to end at, and whether it has arrived.
187-
*
188-
* <p>The timers run on a thread frozen while the device sleeps or the process is cached, so one
189-
* scheduled for 30s can fire hours later. Ending at the wake-up time turns an app start the user
190-
* walked away from into a multi-hour transaction, so an expired timeout ends at the instant it
191-
* fell due instead.
192-
*
193-
* <p>Only a {@link Deadline} can say whether it expired: the executor's own delay stops during
194-
* deep sleep, and the wall clock can step either way while the timer waits.
195-
*/
196-
private static final class Expiry {
197-
198-
private final @NotNull Deadline deadline;
199-
private final @NotNull Timestamp expiredAt;
200-
201-
Expiry(final @NotNull Deadline deadline, final @NotNull Timestamp expiredAt) {
202-
this.deadline = deadline;
203-
this.expiredAt = expiredAt;
204-
}
205-
206-
/** The instant to end at, or null to end now because the timeout has not actually expired. */
207-
@Nullable
208-
Timestamp expiredAt() {
209-
return deadline.hasPassed() ? expiredAt : null;
210-
}
211-
}
212-
213156
@Override
214157
public void forceFinish(
215158
final @NotNull SpanStatus status, final boolean dropIfNoChildren, final @Nullable Hint hint) {
216-
forceFinish(status, dropIfNoChildren, hint, null);
217-
}
218-
219-
// Use the finishDate provided to finish the transaction in case the timeout/deadline has passed.
220-
private void forceFinish(
221-
final @NotNull SpanStatus status,
222-
final boolean dropIfNoChildren,
223-
final @Nullable Hint hint,
224-
final @Nullable SentryDate finishDate) {
225159
if (isFinished()) {
226160
return;
227161
}
228162

229-
final @NotNull SentryDate finishTimestamp =
230-
finishDate != null ? finishDate : scopes.getOptions().getDateProvider().now();
163+
final @NotNull SentryDate finishTimestamp = scopes.getOptions().getDateProvider().now();
231164

232165
// abort all child-spans first, this ensures the transaction can be finished,
233166
// even if waitForChildren is true
@@ -377,7 +310,6 @@ private void scheduleDeadlineTimeout() {
377310
if (timersEnabled) {
378311
cancelDeadlineTimer();
379312
isDeadlineTimerRunning.set(true);
380-
deadlineExpiry = expiryIn(deadlineTimeOut);
381313
try {
382314
deadlineTimeoutFuture =
383315
scopes

‎sentry/src/main/java/io/sentry/time/Timestamp.java‎

Lines changed: 0 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,5 @@
11
package io.sentry.time;
22

3-
import io.sentry.SentryDate;
4-
import io.sentry.SentryLongDate;
53
import org.jetbrains.annotations.ApiStatus;
64
import org.jetbrains.annotations.NotNull;
75
import org.jetbrains.annotations.Nullable;
@@ -56,13 +54,4 @@ public int hashCode() {
5654
public @NotNull String toString() {
5755
return "Timestamp{epochNanos=" + epochNanos + '}';
5856
}
59-
60-
/**
61-
* This forms an easy bridge between our old API and the new API.
62-
*
63-
* @return a SentryDate implemented by a SentryLongDate
64-
*/
65-
public SentryDate getSentryDate() {
66-
return new SentryLongDate(epochNanos);
67-
}
6857
}

‎sentry/src/test/java/io/sentry/SentryTracerTest.kt‎

Lines changed: 1 addition & 120 deletions
Original file line numberDiff line numberDiff line change
@@ -5,17 +5,11 @@ import io.sentry.profiling.ProfileRecordingState
55
import io.sentry.protocol.SentryId
66
import io.sentry.protocol.TransactionNameSource
77
import io.sentry.protocol.User
8-
import io.sentry.test.DeferredExecutorService
98
import io.sentry.test.createTestScopes
109
import io.sentry.test.getProperty
11-
import io.sentry.time.EpochClock
12-
import io.sentry.time.FixedEpochClock
13-
import io.sentry.time.MonotonicTicker
14-
import io.sentry.time.TestMonotonicTicker
1510
import io.sentry.util.thread.IThreadChecker
1611
import java.time.LocalDateTime
1712
import java.time.ZoneOffset
18-
import java.util.concurrent.TimeUnit
1913
import kotlin.test.Test
2014
import kotlin.test.assertEquals
2115
import kotlin.test.assertFalse
@@ -40,18 +34,8 @@ import org.mockito.kotlin.verify
4034
import org.mockito.kotlin.whenever
4135

4236
class SentryTracerTest {
43-
/** The clocks have getters but no setters on options, so a test fakes them by overriding. */
44-
private class TestOptions : SentryOptions() {
45-
var testEpochClock: EpochClock? = null
46-
var testTicker: MonotonicTicker? = null
47-
48-
override fun getEpochClock(): EpochClock = testEpochClock ?: super.getEpochClock()
49-
50-
override fun getMonotonicTicker(): MonotonicTicker = testTicker ?: super.getMonotonicTicker()
51-
}
52-
5337
private class Fixture {
54-
val options = TestOptions()
38+
val options = SentryOptions()
5539
val scopes: Scopes
5640
val compositePerformanceCollector: CompositePerformanceCollector
5741

@@ -95,32 +79,6 @@ class SentryTracerTest {
9579

9680
private val fixture = Fixture()
9781

98-
/** An arbitrary but fixed instant the clock tests measure from. */
99-
private val start = 1_000_000_000_000L
100-
101-
/**
102-
* Everything the timeout logic reads, under the test's control: what time it is, how much time
103-
* has passed, and when the timer gets to run.
104-
*/
105-
private class Clocks(startEpochNanos: Long) {
106-
val epoch = FixedEpochClock(startEpochNanos)
107-
val ticker = TestMonotonicTicker()
108-
val timer = DeferredExecutorService()
109-
110-
/** Time passing for real: every clock moves together, as they do on a device. */
111-
fun advance(amount: Long, unit: TimeUnit) {
112-
epoch.epochNanos += unit.toNanos(amount)
113-
ticker.advance(amount, unit)
114-
}
115-
116-
fun installOn(options: TestOptions) {
117-
options.testEpochClock = epoch
118-
options.testTicker = ticker
119-
options.timerExecutorService = timer
120-
options.dateProvider = SentryDateProvider { SentryLongDate(epoch.epochNanos) }
121-
}
122-
}
123-
12482
@Test
12583
fun `transfer origin from transaction options to transaction context`() {
12684
fixture.getSut()
@@ -1145,83 +1103,6 @@ class SentryTracerTest {
11451103
assertEquals(SpanStatus.DEADLINE_EXCEEDED, span.status)
11461104
}
11471105

1148-
@Test
1149-
fun `when the deadline timer fires late, tx and children end when the deadline fell due`() {
1150-
val clocks = Clocks(start)
1151-
clocks.installOn(fixture.options)
1152-
val transaction = fixture.getSut(deadlineTimeout = 20)
1153-
val span = transaction.startChild("op")
1154-
1155-
// the device sleeps through the deadline; the timer thread only runs again three hours on
1156-
clocks.advance(3, TimeUnit.HOURS)
1157-
clocks.timer.runAll()
1158-
1159-
val due = start + TimeUnit.MILLISECONDS.toNanos(20)
1160-
assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(due)
1161-
assertThat(span.finishDate!!.nanoTimestamp()).isEqualTo(due)
1162-
}
1163-
1164-
@Test
1165-
fun `when the wall clock steps back past the deadline, the transaction still ends when it fell due`() {
1166-
val clocks = Clocks(start)
1167-
clocks.installOn(fixture.options)
1168-
val transaction = fixture.getSut(deadlineTimeout = 20)
1169-
1170-
// an NTP correction drags the wall clock back while the timer waits, so the due instant now
1171-
// looks like it is ahead of us. Whether the deadline expired is not the wall clock's to say
1172-
clocks.epoch.epochNanos = start - TimeUnit.HOURS.toNanos(1)
1173-
clocks.ticker.advance(20, TimeUnit.MILLISECONDS)
1174-
clocks.timer.runAll()
1175-
1176-
assertThat(transaction.finishDate!!.nanoTimestamp())
1177-
.isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20))
1178-
}
1179-
1180-
@Test
1181-
fun `when the deadline timer fires on time, the transaction ends when it fell due`() {
1182-
val clocks = Clocks(start)
1183-
clocks.installOn(fixture.options)
1184-
val transaction = fixture.getSut(deadlineTimeout = 20)
1185-
transaction.startChild("op")
1186-
1187-
clocks.advance(20, TimeUnit.MILLISECONDS)
1188-
clocks.timer.runAll()
1189-
1190-
// an expired deadline ends the transaction at the deadline, not at whenever the timer ran
1191-
assertThat(transaction.finishDate!!.nanoTimestamp())
1192-
.isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20))
1193-
}
1194-
1195-
@Test
1196-
fun `when the deadline has not expired, the transaction ends now`() {
1197-
val clocks = Clocks(start)
1198-
clocks.installOn(fixture.options)
1199-
// scheduling fails, so the tracer finishes inline while the deadline is still in the future
1200-
val executor = mock<ISentryExecutorService>()
1201-
whenever(executor.schedule(any(), any())).thenThrow(RuntimeException("rejected"))
1202-
1203-
val transaction =
1204-
fixture.getSut(
1205-
optionsConfiguration = { it.timerExecutorService = executor },
1206-
deadlineTimeout = 20,
1207-
)
1208-
1209-
assertThat(transaction.finishDate!!.nanoTimestamp()).isEqualTo(start)
1210-
}
1211-
1212-
@Test
1213-
fun `when the idle timer fires late, the transaction ends when the idle timeout fell due`() {
1214-
val clocks = Clocks(start)
1215-
clocks.installOn(fixture.options)
1216-
val transaction = fixture.getSut(idleTimeout = 20)
1217-
1218-
clocks.advance(3, TimeUnit.HOURS)
1219-
clocks.timer.runAll()
1220-
1221-
assertThat(transaction.finishDate!!.nanoTimestamp())
1222-
.isEqualTo(start + TimeUnit.MILLISECONDS.toNanos(20))
1223-
}
1224-
12251106
@Test
12261107
fun `when transaction is finished before deadline is reached, deadline should not be running anymore`() {
12271108
val transaction = fixture.getSut(deadlineTimeout = 1000)

0 commit comments

Comments
 (0)