Skip to content

Commit 0ab689f

Browse files
runningcodeclaude
runningcode
and
claude
authored
fix(clientreport): Stop deserializing discarded logs (JAVA-662) (#5835)
* fix(clientreport): Stop deserializing discarded logs (JAVA-662) ClientReportRecorder counted discarded log and metric items by fully deserializing the envelope payload just to read its size. On the discard path this runs continuously under sustained rate limiting, and the JSON reader's error-tolerant recovery throws an exception per token, pinning CPU cores in a busy-loop (fillInStackTrace dominated the profile). The item count is already stored in the envelope item header, so read it from there instead of deserializing. Byte counts still come from the raw data. This makes the discard path O(1) and allocation/exception-free. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> * changelog * test(clientreport): Cover both onDiscard restore entry points (JAVA-662) The two tests asserting that restoring counts from an attached client report does not re-fire onDiscard were named for their setup rather than for what actually differed between them, which made the pair read as an accidental duplicate. Name each for its entry point and share the setup and verifications, so it is clear the property is being pinned for both recordLostEnvelope and recordLostEnvelopeItem. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 4.8 <noreply@anthropic.com>
1 parent 69bdef7 commit 0ab689f

5 files changed

Lines changed: 145 additions & 54 deletions

File tree

‎CHANGELOG.md‎

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

33
## Unreleased
44

5+
### Fixes
6+
7+
- Avoid a CPU busy-loop when recording discarded log or metric envelopes under rate limiting ([#5835](https://github.com/getsentry/sentry-java/pull/5835))
8+
- `ClientReportRecorder` now reads the item count from the envelope item header instead of deserializing the payload, which under sustained rate limiting could pin CPU cores while repeatedly throwing exceptions
9+
510
### Performance
611

712
- Remove an unused lock from `SentryPerformanceProvider`, which was allocated on every cold start in `ContentProvider.onCreate` without ever being acquired ([#5871](https://github.com/getsentry/sentry-java/pull/5871))

‎sentry/api/sentry.api‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3120,6 +3120,7 @@ public final class io/sentry/SentryEnvelopeItemHeader : io/sentry/JsonSerializab
31203120
public fun getAttachmentType ()Ljava/lang/String;
31213121
public fun getContentType ()Ljava/lang/String;
31223122
public fun getFileName ()Ljava/lang/String;
3123+
public fun getItemCount ()Ljava/lang/Integer;
31233124
public fun getLength ()I
31243125
public fun getPlatform ()Ljava/lang/String;
31253126
public fun getType ()Lio/sentry/SentryItemType;

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

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,10 @@ public int getLength() {
5353
return platform;
5454
}
5555

56+
public @Nullable Integer getItemCount() {
57+
return itemCount;
58+
}
59+
5660
@Nullable
5761
Integer getMetaLength() {
5862
if (calculateMetaLength != null) {

‎sentry/src/main/java/io/sentry/clientreport/ClientReportRecorder.java‎

Lines changed: 19 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -6,10 +6,6 @@
66
import io.sentry.SentryEnvelopeItem;
77
import io.sentry.SentryItemType;
88
import io.sentry.SentryLevel;
9-
import io.sentry.SentryLogEvent;
10-
import io.sentry.SentryLogEvents;
11-
import io.sentry.SentryMetricsEvent;
12-
import io.sentry.SentryMetricsEvents;
139
import io.sentry.SentryOptions;
1410
import io.sentry.protocol.SentrySpan;
1511
import io.sentry.protocol.SentryTransaction;
@@ -105,34 +101,18 @@ public void recordLostEnvelopeItem(
105101
recordLostEventInternal(reason.getReason(), itemCategory.getCategory(), 1L);
106102
executeOnDiscard(reason, itemCategory, 1L);
107103
} else if (itemCategory.equals(DataCategory.LogItem)) {
108-
final @Nullable SentryLogEvents logs = envelopeItem.getLogs(options.getSerializer());
109-
if (logs != null) {
110-
final @NotNull List<SentryLogEvent> items = logs.getItems();
111-
final long count = items.size();
112-
recordLostEventInternal(reason.getReason(), itemCategory.getCategory(), count);
113-
final long logBytes = envelopeItem.getData().length;
114-
recordLostEventInternal(
115-
reason.getReason(), DataCategory.LogByte.getCategory(), logBytes);
116-
executeOnDiscard(reason, itemCategory, count);
117-
} else {
118-
options.getLogger().log(SentryLevel.ERROR, "Unable to parse lost logs envelope item.");
119-
}
104+
final long count = itemCountFromHeader(envelopeItem);
105+
recordLostEventInternal(reason.getReason(), itemCategory.getCategory(), count);
106+
final long logBytes = envelopeItem.getData().length;
107+
recordLostEventInternal(reason.getReason(), DataCategory.LogByte.getCategory(), logBytes);
108+
executeOnDiscard(reason, itemCategory, count);
120109
} else if (itemCategory.equals(DataCategory.TraceMetric)) {
121-
final @Nullable SentryMetricsEvents metrics =
122-
envelopeItem.getMetrics(options.getSerializer());
123-
if (metrics != null) {
124-
final @NotNull List<SentryMetricsEvent> items = metrics.getItems();
125-
final long count = items.size();
126-
recordLostEventInternal(reason.getReason(), itemCategory.getCategory(), count);
127-
final long metricBytes = envelopeItem.getData().length;
128-
recordLostEventInternal(
129-
reason.getReason(), DataCategory.TraceMetricByte.getCategory(), metricBytes);
130-
executeOnDiscard(reason, itemCategory, count);
131-
} else {
132-
options
133-
.getLogger()
134-
.log(SentryLevel.ERROR, "Unable to parse lost metrics envelope item.");
135-
}
110+
final long count = itemCountFromHeader(envelopeItem);
111+
recordLostEventInternal(reason.getReason(), itemCategory.getCategory(), count);
112+
final long metricBytes = envelopeItem.getData().length;
113+
recordLostEventInternal(
114+
reason.getReason(), DataCategory.TraceMetricByte.getCategory(), metricBytes);
115+
executeOnDiscard(reason, itemCategory, count);
136116
} else {
137117
recordLostEventInternal(reason.getReason(), itemCategory.getCategory(), 1L);
138118
executeOnDiscard(reason, itemCategory, 1L);
@@ -176,6 +156,14 @@ private void recordLostEventInternal(
176156
storage.addCount(key, countToAdd);
177157
}
178158

159+
// The number of items batched into a log or metric envelope item is stored in its header, so we
160+
// read it from there instead of deserializing the payload. Deserializing on the discard path is
161+
// expensive and, under sustained rate limiting, caused a CPU busy-loop (JAVA-662).
162+
private long itemCountFromHeader(final @NotNull SentryEnvelopeItem envelopeItem) {
163+
final @Nullable Integer itemCount = envelopeItem.getHeader().getItemCount();
164+
return itemCount != null ? itemCount : 1L;
165+
}
166+
179167
@Nullable
180168
ClientReport resetCountsAndGenerateClientReport() {
181169
final Date currentDate = DateUtils.getCurrentDateTime();

‎sentry/src/test/java/io/sentry/clientreport/ClientReportTest.kt‎

Lines changed: 116 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,9 @@ import io.sentry.Sentry
1515
import io.sentry.SentryEnvelope
1616
import io.sentry.SentryEnvelopeHeader
1717
import io.sentry.SentryEnvelopeItem
18+
import io.sentry.SentryEnvelopeItemHeader
1819
import io.sentry.SentryEvent
20+
import io.sentry.SentryItemType
1921
import io.sentry.SentryLogEvent
2022
import io.sentry.SentryLogEvents
2123
import io.sentry.SentryLogLevel
@@ -46,11 +48,17 @@ import java.util.UUID
4648
import kotlin.test.Test
4749
import kotlin.test.assertEquals
4850
import kotlin.test.assertTrue
51+
import org.mockito.kotlin.any
52+
import org.mockito.kotlin.doReturn
4953
import org.mockito.kotlin.mock
54+
import org.mockito.kotlin.never
5055
import org.mockito.kotlin.times
5156
import org.mockito.kotlin.verify
5257
import org.mockito.kotlin.whenever
5358

59+
private const val LOG_CONTENT_TYPE = "application/vnd.sentry.items.log+json"
60+
private const val METRIC_CONTENT_TYPE = "application/vnd.sentry.items.trace-metric+json"
61+
5462
class ClientReportTest {
5563
lateinit var opts: SentryOptions
5664
lateinit var clientReportRecorder: ClientReportRecorder
@@ -312,28 +320,24 @@ class ClientReportTest {
312320
}
313321

314322
@Test
315-
fun `recording envelope with lost client report does not duplicate onDiscard executions`() {
316-
val onDiscardMock = mock<SentryOptions.OnDiscardCallback>()
317-
givenClientReportRecorder { options -> options.onDiscard = onDiscardMock }
318-
319-
clientReportRecorder.recordLostEvent(DiscardReason.CACHE_OVERFLOW, DataCategory.Attachment)
320-
clientReportRecorder.recordLostEvent(DiscardReason.CACHE_OVERFLOW, DataCategory.Attachment)
321-
clientReportRecorder.recordLostEvent(DiscardReason.RATELIMIT_BACKOFF, DataCategory.Error)
322-
clientReportRecorder.recordLostEvent(DiscardReason.QUEUE_OVERFLOW, DataCategory.Error)
323-
clientReportRecorder.recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Profile)
324-
325-
val envelope = clientReportRecorder.attachReportToEnvelope(testHelper.newEnvelope())
326-
clientReportRecorder.recordLostEnvelope(DiscardReason.EVENT_PROCESSOR, envelope)
327-
328-
verify(onDiscardMock, times(2))
329-
.execute(DiscardReason.CACHE_OVERFLOW, DataCategory.Attachment, 1)
330-
verify(onDiscardMock, times(1)).execute(DiscardReason.RATELIMIT_BACKOFF, DataCategory.Error, 1)
331-
verify(onDiscardMock, times(1)).execute(DiscardReason.QUEUE_OVERFLOW, DataCategory.Error, 1)
332-
verify(onDiscardMock, times(1)).execute(DiscardReason.BEFORE_SEND, DataCategory.Profile, 1)
323+
fun `restoring counts via recordLostEnvelope does not fire onDiscard again`() {
324+
assertRestoringCountsDoesNotFireOnDiscard { recorder, envelope ->
325+
recorder.recordLostEnvelope(DiscardReason.EVENT_PROCESSOR, envelope)
326+
}
333327
}
334328

335329
@Test
336-
fun `recording lost client report does not duplicate onDiscard executions`() {
330+
fun `restoring counts via recordLostEnvelopeItem does not fire onDiscard again`() {
331+
assertRestoringCountsDoesNotFireOnDiscard { recorder, envelope ->
332+
recorder.recordLostEnvelopeItem(DiscardReason.NETWORK_ERROR, envelope.items.first())
333+
}
334+
}
335+
336+
// Counts restored from an attached client report were already reported once, so replaying them
337+
// must not fire onDiscard a second time. Both public entry points have to hold the property.
338+
private fun assertRestoringCountsDoesNotFireOnDiscard(
339+
recordLost: (ClientReportRecorder, SentryEnvelope) -> Unit
340+
) {
337341
val onDiscardMock = mock<SentryOptions.OnDiscardCallback>()
338342
givenClientReportRecorder { options -> options.onDiscard = onDiscardMock }
339343

@@ -344,7 +348,7 @@ class ClientReportTest {
344348
clientReportRecorder.recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.Profile)
345349

346350
val envelope = clientReportRecorder.attachReportToEnvelope(testHelper.newEnvelope())
347-
clientReportRecorder.recordLostEnvelopeItem(DiscardReason.NETWORK_ERROR, envelope.items.first())
351+
recordLost(clientReportRecorder, envelope)
348352

349353
verify(onDiscardMock, times(2))
350354
.execute(DiscardReason.CACHE_OVERFLOW, DataCategory.Attachment, 1)
@@ -417,6 +421,98 @@ class ClientReportTest {
417421
assertEquals(envelope.items.first().data.size.toLong(), metricByteItem.quantity)
418422
}
419423

424+
@Test
425+
fun `recording lost log item reads count from the header without deserializing the payload`() {
426+
val onDiscardMock = mock<SentryOptions.OnDiscardCallback>()
427+
givenClientReportRecorder { options -> options.onDiscard = onDiscardMock }
428+
429+
val payload = "irrelevant payload".toByteArray()
430+
val item = mockEnvelopeItem(SentryItemType.Log, LOG_CONTENT_TYPE, itemCount = 5, data = payload)
431+
432+
clientReportRecorder.recordLostEnvelopeItem(DiscardReason.NETWORK_ERROR, item)
433+
434+
// Deserializing here is what pinned CPU cores under sustained rate limiting (JAVA-662), so the
435+
// count must come from the header and the payload must stay untouched.
436+
verify(item, never()).getLogs(any())
437+
verify(onDiscardMock, times(1)).execute(DiscardReason.NETWORK_ERROR, DataCategory.LogItem, 5)
438+
439+
val clientReport = clientReportRecorder.resetCountsAndGenerateClientReport()
440+
assertEquals(5, clientReport.quantityOf(DataCategory.LogItem))
441+
assertEquals(payload.size.toLong(), clientReport.quantityOf(DataCategory.LogByte))
442+
}
443+
444+
@Test
445+
fun `recording lost metric item reads count from the header without deserializing the payload`() {
446+
val onDiscardMock = mock<SentryOptions.OnDiscardCallback>()
447+
givenClientReportRecorder { options -> options.onDiscard = onDiscardMock }
448+
449+
val payload = "irrelevant payload".toByteArray()
450+
val item =
451+
mockEnvelopeItem(
452+
SentryItemType.TraceMetric,
453+
METRIC_CONTENT_TYPE,
454+
itemCount = 5,
455+
data = payload,
456+
)
457+
458+
clientReportRecorder.recordLostEnvelopeItem(DiscardReason.NETWORK_ERROR, item)
459+
460+
verify(item, never()).getMetrics(any())
461+
verify(onDiscardMock, times(1))
462+
.execute(DiscardReason.NETWORK_ERROR, DataCategory.TraceMetric, 5)
463+
464+
val clientReport = clientReportRecorder.resetCountsAndGenerateClientReport()
465+
assertEquals(5, clientReport.quantityOf(DataCategory.TraceMetric))
466+
assertEquals(payload.size.toLong(), clientReport.quantityOf(DataCategory.TraceMetricByte))
467+
}
468+
469+
@Test
470+
fun `recording lost log item without item count in header falls back to one`() {
471+
givenClientReportRecorder()
472+
473+
val item =
474+
mockEnvelopeItem(SentryItemType.Log, LOG_CONTENT_TYPE, itemCount = null, data = ByteArray(0))
475+
476+
clientReportRecorder.recordLostEnvelopeItem(DiscardReason.NETWORK_ERROR, item)
477+
478+
val clientReport = clientReportRecorder.resetCountsAndGenerateClientReport()
479+
assertEquals(1, clientReport.quantityOf(DataCategory.LogItem))
480+
}
481+
482+
@Test
483+
fun `recording lost metric item without item count in header falls back to one`() {
484+
givenClientReportRecorder()
485+
486+
val item =
487+
mockEnvelopeItem(
488+
SentryItemType.TraceMetric,
489+
METRIC_CONTENT_TYPE,
490+
itemCount = null,
491+
data = ByteArray(0),
492+
)
493+
494+
clientReportRecorder.recordLostEnvelopeItem(DiscardReason.NETWORK_ERROR, item)
495+
496+
val clientReport = clientReportRecorder.resetCountsAndGenerateClientReport()
497+
assertEquals(1, clientReport.quantityOf(DataCategory.TraceMetric))
498+
}
499+
500+
private fun mockEnvelopeItem(
501+
type: SentryItemType,
502+
contentType: String,
503+
itemCount: Int?,
504+
data: ByteArray,
505+
): SentryEnvelopeItem {
506+
val itemHeader = SentryEnvelopeItemHeader(type, 0, contentType, null, null, null, itemCount)
507+
return mock {
508+
on { it.header } doReturn itemHeader
509+
on { it.data } doReturn data
510+
}
511+
}
512+
513+
private fun ClientReport?.quantityOf(category: DataCategory): Long =
514+
this!!.discardedEvents!!.first { it.category == category.category }.quantity
515+
420516
private fun givenClientReportRecorder(
421517
callback: Sentry.OptionsConfiguration<SentryOptions>? = null
422518
) {
@@ -470,9 +566,6 @@ class ClientReportTestHelper(val options: SentryOptions) {
470566
return SentryEnvelope(header, items.toList())
471567
}
472568

473-
fun toEnvelopeItem(clientReport: ClientReport): SentryEnvelopeItem =
474-
SentryEnvelopeItem.fromClientReport(options.serializer, clientReport)
475-
476569
companion object {
477570
fun retryableHint() = HintUtils.createWithTypeCheckHint(TestRetryable())
478571

0 commit comments

Comments
 (0)