diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ApplicationExitInfoEventProcessorTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ApplicationExitInfoEventProcessorTest.kt index d5b916d3b44..1da36ea8faa 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ApplicationExitInfoEventProcessorTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/ApplicationExitInfoEventProcessorTest.kt @@ -41,7 +41,6 @@ import io.sentry.cache.PersistingScopeObserver.TAGS_FILENAME import io.sentry.cache.PersistingScopeObserver.TRACE_FILENAME import io.sentry.cache.PersistingScopeObserver.TRANSACTION_FILENAME import io.sentry.cache.PersistingScopeObserver.USER_FILENAME -import io.sentry.cache.tape.QueueFile import io.sentry.hints.AbnormalExit import io.sentry.hints.Backfillable import io.sentry.protocol.Browser @@ -60,8 +59,8 @@ import io.sentry.protocol.SentryStackTrace import io.sentry.protocol.SentryThread import io.sentry.protocol.User import io.sentry.util.HintUtils -import java.io.ByteArrayOutputStream import java.io.File +import java.io.StringWriter import kotlin.test.BeforeTest import kotlin.test.Test import kotlin.test.assertEquals @@ -166,12 +165,12 @@ class ApplicationExitInfoEventProcessorTest { val dir = File(options.cacheDirPath, SCOPE_CACHE).also { it.mkdirs() } val file = File(dir, filename) if (filename == BREADCRUMBS_FILENAME) { - val queueFile = QueueFile.Builder(file).build() - (entity as List).forEach { crumb -> - val baos = ByteArrayOutputStream() - options.serializer.serialize(crumb, baos.writer()) - queueFile.add(baos.toByteArray()) - } + // breadcrumbs are stored as newline-delimited JSON, one breadcrumb per line + file.writeText( + (entity as List).joinToString(separator = "") { crumb -> + StringWriter().also { options.serializer.serialize(crumb, it) }.toString() + "\n" + } + ) } else { options.serializer.serialize(entity, file.writer()) } diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt index 2bd26051c07..aa54002fd41 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidTest.kt @@ -44,15 +44,14 @@ import io.sentry.cache.PersistingScopeObserver.BREADCRUMBS_FILENAME import io.sentry.cache.PersistingScopeObserver.REPLAY_FILENAME import io.sentry.cache.PersistingScopeObserver.SCOPE_CACHE import io.sentry.cache.PersistingScopeObserver.TRANSACTION_FILENAME -import io.sentry.cache.tape.QueueFile import io.sentry.protocol.Contexts import io.sentry.protocol.SentryId import io.sentry.spotlight.SpotlightIntegration import io.sentry.test.applyTestOptions import io.sentry.transport.NoOpEnvelopeCache import io.sentry.util.StringUtils -import java.io.ByteArrayOutputStream import java.io.File +import java.io.StringWriter import java.nio.file.Files import java.util.concurrent.TimeUnit import java.util.concurrent.atomic.AtomicBoolean @@ -564,17 +563,14 @@ class SentryAndroidTest { private fun prefillScopeCache(options: SentryOptions, cacheDir: String) { val scopeDir = File(cacheDir, SCOPE_CACHE).also { it.mkdirs() } - val queueFile = QueueFile.Builder(File(scopeDir, BREADCRUMBS_FILENAME)).build() - val baos = ByteArrayOutputStream() - options.serializer.serialize( + val breadcrumb = Breadcrumb(DateUtils.getDateTime("2009-11-16T01:08:47.000Z")).apply { message = "Debug!" type = "debug" level = DEBUG - }, - baos.writer(), - ) - queueFile.add(baos.toByteArray()) + } + val serialized = StringWriter().also { options.serializer.serialize(breadcrumb, it) }.toString() + File(scopeDir, BREADCRUMBS_FILENAME).writeText("$serialized\n") File(scopeDir, TRANSACTION_FILENAME).writeText("\"MainActivity\"") File(scopeDir, REPLAY_FILENAME).writeText("\"afcb46b1140ade5187c4bbb5daa804df\"") File(options.getCacheDirPath(), "replay_afcb46b1140ade5187c4bbb5daa804df").mkdirs() diff --git a/sentry-android-replay/src/test/java/io/sentry/android/replay/ReplayIntegrationTest.kt b/sentry-android-replay/src/test/java/io/sentry/android/replay/ReplayIntegrationTest.kt index 32b7f4e9285..32ddc11196b 100644 --- a/sentry-android-replay/src/test/java/io/sentry/android/replay/ReplayIntegrationTest.kt +++ b/sentry-android-replay/src/test/java/io/sentry/android/replay/ReplayIntegrationTest.kt @@ -36,7 +36,6 @@ import io.sentry.android.replay.capture.SessionCaptureStrategyTest.Fixture.Compa import io.sentry.android.replay.gestures.GestureRecorder import io.sentry.android.replay.util.ReplayShadowMediaCodec import io.sentry.cache.PersistingScopeObserver -import io.sentry.cache.tape.QueueFile import io.sentry.protocol.SentryException import io.sentry.protocol.SentryId import io.sentry.rrweb.RRWebBreadcrumbEvent @@ -48,8 +47,8 @@ import io.sentry.transport.CurrentDateProvider import io.sentry.transport.ICurrentDateProvider import io.sentry.transport.RateLimiter import io.sentry.util.Random -import java.io.ByteArrayOutputStream import java.io.File +import java.io.StringWriter import kotlin.test.BeforeTest import kotlin.test.Test import kotlin.test.assertEquals @@ -501,18 +500,16 @@ class ReplayIntegrationTest { it.writeText("\"$oldReplayId\"") } val breadcrumbsFile = File(scopeCache, PersistingScopeObserver.BREADCRUMBS_FILENAME) - val queueFile = QueueFile.Builder(breadcrumbsFile).build() - val baos = ByteArrayOutputStream() - fixture.options.serializer.serialize( + val breadcrumb = Breadcrumb(DateUtils.getDateTime("2024-07-11T10:25:23.454Z")).apply { category = "navigation" type = "navigation" setData("from", "from") setData("to", "to") - }, - baos.writer(), - ) - queueFile.add(baos.toByteArray()) + } + val serialized = + StringWriter().also { fixture.options.serializer.serialize(breadcrumb, it) }.toString() + breadcrumbsFile.writeText("$serialized\n") File(oldReplay, ONGOING_SEGMENT).also { it.writeText( """ diff --git a/sentry/api/sentry.api b/sentry/api/sentry.api index 61d531ea53e..760a721c7e2 100644 --- a/sentry/api/sentry.api +++ b/sentry/api/sentry.api @@ -4821,6 +4821,13 @@ public final class io/sentry/backpressure/NoOpBackpressureMonitor : io/sentry/ba public fun start ()V } +public final class io/sentry/cache/BreadcrumbAppendLog { + public fun (Lio/sentry/SentryOptions;Ljava/io/File;)V + public fun append (Ljava/util/List;)V + public fun clear ()V + public fun read ()Ljava/util/List; +} + public final class io/sentry/cache/CacheUtils { public static fun read (Lio/sentry/SentryOptions;Ljava/lang/String;Ljava/lang/String;Ljava/lang/Class;Lio/sentry/JsonDeserializer;)Ljava/lang/Object; public static fun store (Lio/sentry/SentryOptions;Ljava/lang/Object;Ljava/lang/String;Ljava/lang/String;)V diff --git a/sentry/src/main/java/io/sentry/cache/BreadcrumbAppendLog.java b/sentry/src/main/java/io/sentry/cache/BreadcrumbAppendLog.java new file mode 100644 index 00000000000..64604987068 --- /dev/null +++ b/sentry/src/main/java/io/sentry/cache/BreadcrumbAppendLog.java @@ -0,0 +1,250 @@ +package io.sentry.cache; + +import static io.sentry.SentryLevel.DEBUG; +import static io.sentry.SentryLevel.ERROR; + +import io.sentry.Breadcrumb; +import io.sentry.SentryOptions; +import java.io.BufferedReader; +import java.io.BufferedWriter; +import java.io.File; +import java.io.FileInputStream; +import java.io.FileOutputStream; +import java.io.InputStreamReader; +import java.io.OutputStreamWriter; +import java.io.StringReader; +import java.io.Writer; +import java.nio.charset.Charset; +import java.util.ArrayList; +import java.util.List; +import org.jetbrains.annotations.ApiStatus; +import org.jetbrains.annotations.NotNull; +import org.jetbrains.annotations.Nullable; + +/** + * A bounded, newline-delimited JSON append log for breadcrumbs. + * + *

Breadcrumbs are only ever appended in bulk and read back as a whole list on the next launch, + * so this stores one serialized breadcrumb per line rather than using a random-access queue. A torn + * trailing line — the realistic failure when the process dies mid-write — fails to deserialize and + * is skipped, leaving every earlier breadcrumb readable. + * + *

The log is bounded by rewriting it down to the newest {@code maxBreadcrumbs} entries once it + * grows past {@code compactionThresholdFactor} times that limit, so appends stay O(1) amortized. + * + *

Not thread-safe; callers must serialize access. {@link PersistingScopeObserver} only touches + * it from the flush task on its single-threaded executor. + * + *

A null file means there is nowhere to persist to (no cache dir configured); every operation + * then becomes a no-op. + */ +@ApiStatus.Internal +public final class BreadcrumbAppendLog { + + @SuppressWarnings("CharsetObjectCanBeUsed") + private static final Charset UTF_8 = Charset.forName("UTF-8"); + + /** Compact once the log holds this many times {@code maxBreadcrumbs} lines. */ + private static final int COMPACTION_THRESHOLD_FACTOR = 2; + + private final @NotNull SentryOptions options; + private final @Nullable File file; + private final int maxBreadcrumbs; + + /** + * Lines currently in the file. Tracked in memory so appends don't have to count them on disk; + * seeded from the file on first use so a log inherited from the previous run is still bounded. + */ + private int lineCount; + + private boolean lineCountKnown; + + public BreadcrumbAppendLog(final @NotNull SentryOptions options, final @Nullable File file) { + this.options = options; + this.file = file; + // a non-positive limit would make the compaction threshold zero and compact on every append + this.maxBreadcrumbs = Math.max(1, options.getMaxBreadcrumbs()); + } + + /** Appends breadcrumbs, compacting afterwards if the log has outgrown its bound. */ + public void append(final @NotNull List breadcrumbs) { + if (file == null || breadcrumbs.isEmpty()) { + return; + } + // otherwise we'd append newline-delimited JSON onto a file in some older format + discardForeignFormat(); + ensureLineCount(); + + int appended = 0; + try (final Writer writer = + new BufferedWriter(new OutputStreamWriter(new FileOutputStream(file, true), UTF_8))) { + for (final @NotNull Breadcrumb crumb : breadcrumbs) { + try { + options.getSerializer().serialize(crumb, writer); + } catch (Throwable e) { + // the partially written line would corrupt the log, so stop rather than write more + options.getLogger().log(ERROR, e, "Error serializing breadcrumb, dropping the rest"); + break; + } + writer.write('\n'); + appended++; + } + } catch (Throwable e) { + // the line count is unreliable once a write fails part-way, so re-read it next time + options.getLogger().log(ERROR, e, "Error appending breadcrumbs to %s", file.getName()); + lineCountKnown = false; + return; + } + + lineCount += appended; + if (lineCount > maxBreadcrumbs * COMPACTION_THRESHOLD_FACTOR) { + compact(); + } + } + + /** Reads the persisted breadcrumbs, oldest first, skipping any line that fails to parse. */ + public @NotNull List read() { + final @NotNull List breadcrumbs = readAll(); + return breadcrumbs.size() <= maxBreadcrumbs + ? breadcrumbs + : new ArrayList<>( + breadcrumbs.subList(breadcrumbs.size() - maxBreadcrumbs, breadcrumbs.size())); + } + + /** Empties the log. */ + public void clear() { + if (file == null) { + return; + } + if (file.exists() && !file.delete()) { + options.getLogger().log(DEBUG, "Failed to delete %s", file.getAbsolutePath()); + } + lineCount = 0; + lineCountKnown = true; + } + + private @NotNull List readAll() { + discardForeignFormat(); + if (file == null || !file.exists()) { + return new ArrayList<>(); + } + + final @NotNull List breadcrumbs = new ArrayList<>(); + try (final BufferedReader reader = + new BufferedReader(new InputStreamReader(new FileInputStream(file), UTF_8))) { + String line; + while ((line = reader.readLine()) != null) { + if (line.isEmpty()) { + continue; + } + final @Nullable Breadcrumb crumb = deserialize(line); + if (crumb != null) { + breadcrumbs.add(crumb); + } + } + } catch (Throwable e) { + options.getLogger().log(ERROR, e, "Error reading breadcrumbs from %s", file.getName()); + } + return breadcrumbs; + } + + /** + * Deletes a file left behind by an older SDK version, which stored breadcrumbs either as a + * QueueFile ring buffer or as a single JSON array. Neither is newline-delimited, so reading them + * line-by-line yields nothing useful; delete instead of leaving stale bytes to be appended to. + */ + private void discardForeignFormat() { + if (file == null || !file.exists()) { + return; + } + final int firstByte = readFirstByte(); + // every line this class writes is a JSON object, so anything else is a foreign format + if (firstByte == -1 || firstByte == '{') { + return; + } + options.getLogger().log(DEBUG, "Discarding breadcrumbs in an unrecognized format"); + clear(); + } + + private int readFirstByte() { + if (file == null) { + return -1; + } + try (final FileInputStream stream = new FileInputStream(file)) { + return stream.read(); + } catch (Throwable e) { + options.getLogger().log(ERROR, e, "Error reading breadcrumbs from %s", file.getName()); + return -1; + } + } + + private @Nullable Breadcrumb deserialize(final @NotNull String line) { + try (final StringReader reader = new StringReader(line)) { + return options.getSerializer().deserialize(reader, Breadcrumb.class); + } catch (Throwable e) { + // a torn trailing line is expected after the process died mid-write, so this isn't an error + options.getLogger().log(DEBUG, "Skipping unreadable breadcrumb line"); + return null; + } + } + + /** Rewrites the log with only the newest {@code maxBreadcrumbs} entries. */ + private void compact() { + if (file == null) { + return; + } + final @NotNull List retained = read(); + final @NotNull File tempFile = new File(file.getPath() + ".tmp"); + + int written = 0; + try (final Writer writer = + new BufferedWriter(new OutputStreamWriter(new FileOutputStream(tempFile), UTF_8))) { + for (final @NotNull Breadcrumb crumb : retained) { + options.getSerializer().serialize(crumb, writer); + writer.write('\n'); + written++; + } + } catch (Throwable e) { + options.getLogger().log(ERROR, e, "Error compacting breadcrumbs, keeping the existing log"); + if (tempFile.exists() && !tempFile.delete()) { + options.getLogger().log(DEBUG, "Failed to delete %s", tempFile.getAbsolutePath()); + } + return; + } + + // renameTo is atomic, so a crash here leaves either the old log or the compacted one + if (!tempFile.renameTo(file)) { + options.getLogger().log(ERROR, "Failed to replace %s with the compacted log", file.getName()); + if (!tempFile.delete()) { + options.getLogger().log(DEBUG, "Failed to delete %s", tempFile.getAbsolutePath()); + } + return; + } + lineCount = written; + lineCountKnown = true; + } + + private void ensureLineCount() { + if (lineCountKnown) { + return; + } + lineCount = countLines(); + lineCountKnown = true; + } + + private int countLines() { + if (file == null || !file.exists()) { + return 0; + } + int lines = 0; + try (final BufferedReader reader = + new BufferedReader(new InputStreamReader(new FileInputStream(file), UTF_8))) { + while (reader.readLine() != null) { + lines++; + } + } catch (Throwable e) { + options.getLogger().log(ERROR, e, "Error counting breadcrumbs in %s", file.getName()); + } + return lines; + } +} diff --git a/sentry/src/main/java/io/sentry/cache/PersistingScopeObserver.java b/sentry/src/main/java/io/sentry/cache/PersistingScopeObserver.java index 639131feda3..d6d6d141036 100644 --- a/sentry/src/main/java/io/sentry/cache/PersistingScopeObserver.java +++ b/sentry/src/main/java/io/sentry/cache/PersistingScopeObserver.java @@ -10,26 +10,15 @@ import io.sentry.SentryLevel; import io.sentry.SentryOptions; import io.sentry.SpanContext; -import io.sentry.cache.tape.ObjectQueue; -import io.sentry.cache.tape.QueueFile; import io.sentry.protocol.Contexts; import io.sentry.protocol.Request; import io.sentry.protocol.SentryId; import io.sentry.protocol.User; import io.sentry.util.LazyEvaluator; -import java.io.BufferedReader; -import java.io.BufferedWriter; -import java.io.ByteArrayInputStream; import java.io.File; -import java.io.IOException; -import java.io.InputStreamReader; -import java.io.OutputStream; -import java.io.OutputStreamWriter; -import java.io.Reader; -import java.io.Writer; -import java.nio.charset.Charset; import java.util.ArrayList; import java.util.Collection; +import java.util.List; import java.util.Map; import java.util.Queue; import java.util.concurrent.ConcurrentHashMap; @@ -42,8 +31,6 @@ public final class PersistingScopeObserver extends ScopeObserverAdapter { - private static final Charset UTF_8 = Charset.forName("UTF-8"); - /** Sentinel value marking a file that should be deleted rather than written on the next flush. */ private static final Object DELETE_MARKER = new Object(); @@ -61,66 +48,15 @@ public final class PersistingScopeObserver extends ScopeObserverAdapter { public static final String REPLAY_FILENAME = "replay.json"; private @NotNull SentryOptions options; - private final @NotNull LazyEvaluator> breadcrumbsQueue = + private final @NotNull LazyEvaluator breadcrumbsLog = new LazyEvaluator<>( () -> { final File cacheDir = ensureCacheDir(options, SCOPE_CACHE); if (cacheDir == null) { options.getLogger().log(INFO, "Cache dir is not set, cannot store in scope cache"); - return ObjectQueue.createEmpty(); - } - - QueueFile queueFile = null; - final File file = new File(cacheDir, BREADCRUMBS_FILENAME); - try { - try { - queueFile = - new QueueFile.Builder(file) - .size(options.getMaxBreadcrumbs()) - .synchronousWrites(false) - .build(); - } catch (IOException e) { - // if file is corrupted we simply delete it and try to create it again. We accept - // the trade - // off of losing breadcrumbs for ANRs that happened right before the app has - // received an - // update where the new format was introduced - file.delete(); - - queueFile = - new QueueFile.Builder(file) - .size(options.getMaxBreadcrumbs()) - .synchronousWrites(false) - .build(); - } - } catch (IOException e) { - options.getLogger().log(ERROR, "Failed to create breadcrumbs queue", e); - return ObjectQueue.createEmpty(); + return new BreadcrumbAppendLog(options, null); } - return ObjectQueue.create( - queueFile, - new ObjectQueue.Converter() { - @Override - @Nullable - public Breadcrumb from(byte[] source) { - try (final Reader reader = - new BufferedReader( - new InputStreamReader(new ByteArrayInputStream(source), UTF_8))) { - return options.getSerializer().deserialize(reader, Breadcrumb.class); - } catch (Throwable e) { - options.getLogger().log(ERROR, e, "Error reading entity from scope cache"); - } - return null; - } - - @Override - public void toStream(Breadcrumb value, OutputStream sink) throws IOException { - try (final Writer writer = - new BufferedWriter(new OutputStreamWriter(sink, UTF_8))) { - options.getSerializer().serialize(value, writer); - } - } - }); + return new BreadcrumbAppendLog(options, new File(cacheDir, BREADCRUMBS_FILENAME)); }); // Latest pending value per file (or DELETE_MARKER), coalesced until the next flush. @@ -272,36 +208,19 @@ private void flushPending() { } } - boolean breadcrumbsChanged = false; - final @NotNull ObjectQueue queue = breadcrumbsQueue.getValue(); + final @NotNull BreadcrumbAppendLog log = breadcrumbsLog.getValue(); if (pendingBreadcrumbsClear.compareAndSet(true, false)) { - try { - queue.clear(); - breadcrumbsChanged = true; - } catch (IOException e) { - options.getLogger().log(ERROR, "Failed to clear breadcrumbs from file queue", e); - } + log.clear(); } + // drain into a list first so the whole batch goes out in a single append + final @NotNull List drained = new ArrayList<>(); Breadcrumb crumb; while ((crumb = pendingBreadcrumbs.poll()) != null) { - try { - queue.add(crumb); - breadcrumbsChanged = true; - } catch (IOException e) { - options.getLogger().log(ERROR, "Failed to add breadcrumb to file queue", e); - } - } - - if (breadcrumbsChanged) { - try { - // single fsync for the whole batch instead of one per breadcrumb - queue.sync(); - } catch (IOException e) { - options.getLogger().log(ERROR, "Failed to sync breadcrumbs file queue", e); - } + drained.add(crumb); } + log.append(drained); } /** @@ -341,33 +260,20 @@ public static void store( final @NotNull String fileName, final @NotNull Class clazz) { if (fileName.equals(BREADCRUMBS_FILENAME)) { - try { - return clazz.cast(breadcrumbsQueue.getValue().asList()); - } catch (IOException e) { - options.getLogger().log(ERROR, "Unable to read serialized breadcrumbs from QueueFile"); - return null; - } + return clazz.cast(breadcrumbsLog.getValue().read()); } return CacheUtils.read(options, SCOPE_CACHE, fileName, clazz, null); } /** - * Resets the scope cache by deleting the files and/or clearing the QueueFiles. Note: this does - * I/O and should be called from a background thread. + * Resets the scope cache by deleting the persisted files. Note: this does I/O and should be + * called from a background thread. */ public void resetCache() { // NOTE: pending mutations are deliberately left alone. They only ever hold values from the // current process, which is exactly what this reset is clearing the way for; dropping them // would lose scope state set during init. - // since it keeps a reference to the file and we cannot delete it, breadcrumbs we just clear - try { - final @NotNull ObjectQueue queue = breadcrumbsQueue.getValue(); - queue.clear(); - // breadcrumbs use buffered writes, so make the clear durable explicitly - queue.sync(); - } catch (IOException e) { - options.getLogger().log(ERROR, "Failed to clear breadcrumbs from file queue", e); - } + breadcrumbsLog.getValue().clear(); // the rest we can safely delete delete(USER_FILENAME); diff --git a/sentry/src/test/java/io/sentry/cache/BreadcrumbAppendLogTest.kt b/sentry/src/test/java/io/sentry/cache/BreadcrumbAppendLogTest.kt new file mode 100644 index 00000000000..00aa7c55a57 --- /dev/null +++ b/sentry/src/test/java/io/sentry/cache/BreadcrumbAppendLogTest.kt @@ -0,0 +1,196 @@ +package io.sentry.cache + +import com.google.common.truth.Truth.assertThat +import io.sentry.Breadcrumb +import io.sentry.NoOpLogger +import io.sentry.SentryOptions +import java.io.File +import kotlin.test.Test +import org.junit.Rule +import org.junit.rules.TemporaryFolder + +class BreadcrumbAppendLogTest { + @get:Rule val tmpDir = TemporaryFolder() + + private fun options(maxBreadcrumbs: Int = 100) = + SentryOptions().apply { + setLogger(NoOpLogger.getInstance()) + setMaxBreadcrumbs(maxBreadcrumbs) + } + + private fun sut(options: SentryOptions = options(), file: File? = null) = + BreadcrumbAppendLog(options, file ?: File(tmpDir.newFolder(), "breadcrumbs.json")) + + @Test + fun `round-trips appended breadcrumbs in order`() { + val log = sut() + + log.append(listOf(Breadcrumb.debug("one"), Breadcrumb.debug("two"))) + + assertThat(log.read().map { it.message }).containsExactly("one", "two").inOrder() + } + + @Test + fun `appends across separate calls accumulate`() { + val log = sut() + + log.append(listOf(Breadcrumb.debug("one"))) + log.append(listOf(Breadcrumb.debug("two"))) + + assertThat(log.read().map { it.message }).containsExactly("one", "two").inOrder() + } + + @Test + fun `reads back nothing when the file does not exist`() { + assertThat(sut().read()).isEmpty() + } + + @Test + fun `clear empties the log`() { + val log = sut() + log.append(listOf(Breadcrumb.debug("one"))) + + log.clear() + + assertThat(log.read()).isEmpty() + } + + @Test + fun `appends after a clear are retained`() { + val log = sut() + log.append(listOf(Breadcrumb.debug("one"))) + log.clear() + + log.append(listOf(Breadcrumb.debug("two"))) + + assertThat(log.read().map { it.message }).containsExactly("two") + } + + @Test + fun `read is bounded to maxBreadcrumbs, keeping the newest`() { + val log = sut(options(maxBreadcrumbs = 3)) + + log.append((1..5).map { Breadcrumb.debug("crumb-$it") }) + + assertThat(log.read().map { it.message }) + .containsExactly("crumb-3", "crumb-4", "crumb-5") + .inOrder() + } + + @Test + fun `compacts the file once it outgrows the threshold`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + val log = BreadcrumbAppendLog(options(maxBreadcrumbs = 2), file) + + // threshold is maxBreadcrumbs * 2, so the 5th crumb triggers compaction + (1..5).forEach { log.append(listOf(Breadcrumb.debug("crumb-$it"))) } + + assertThat(file.readLines().filter { it.isNotEmpty() }).hasSize(2) + assertThat(log.read().map { it.message }).containsExactly("crumb-4", "crumb-5").inOrder() + } + + @Test + fun `skips a torn trailing line and keeps earlier breadcrumbs`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + val log = BreadcrumbAppendLog(options(), file) + log.append(listOf(Breadcrumb.debug("one"), Breadcrumb.debug("two"))) + + // simulate the process dying mid-write, leaving a partial JSON object on the last line + file.appendText("{\"message\":\"thr") + + assertThat(log.read().map { it.message }).containsExactly("one", "two").inOrder() + } + + @Test + fun `skips a corrupt line in the middle of the log`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + val log = BreadcrumbAppendLog(options(), file) + log.append(listOf(Breadcrumb.debug("one"))) + file.appendText("not json at all\n") + log.append(listOf(Breadcrumb.debug("two"))) + + assertThat(log.read().map { it.message }).containsExactly("one", "two").inOrder() + } + + @Test + fun `bounds a log inherited from a previous run`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + BreadcrumbAppendLog(options(maxBreadcrumbs = 2), file) + .append((1..4).map { Breadcrumb.debug("old-$it") }) + + // a fresh instance has no in-memory line count, so it must recount before appending + val reopened = BreadcrumbAppendLog(options(maxBreadcrumbs = 2), file) + reopened.append(listOf(Breadcrumb.debug("new"))) + + assertThat(file.readLines().filter { it.isNotEmpty() }).hasSize(2) + assertThat(reopened.read().map { it.message }).containsExactly("old-4", "new").inOrder() + } + + @Test + fun `appending nothing does not create the file`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + + BreadcrumbAppendLog(options(), file).append(emptyList()) + + assertThat(file.exists()).isFalse() + } + + @Test + fun `discards a legacy JSON-array file on read`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + file.writeText("""[{"message":"old","type":"debug"}]""") + + assertThat(BreadcrumbAppendLog(options(), file).read()).isEmpty() + assertThat(file.exists()).isFalse() + } + + @Test + fun `discards a legacy binary file before appending`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + // a QueueFile starts with a binary header, not '{' + file.writeBytes(byteArrayOf(0x80.toByte(), 0x00, 0x00, 0x01, 0x00, 0x00)) + val log = BreadcrumbAppendLog(options(), file) + + log.append(listOf(Breadcrumb.debug("new"))) + + assertThat(log.read().map { it.message }).containsExactly("new") + } + + @Test + fun `no-ops without a file`() { + val log = BreadcrumbAppendLog(options(), null) + + log.append(listOf(Breadcrumb.debug("one"))) + log.clear() + + assertThat(log.read()).isEmpty() + } + + @Test + fun `newlines inside breadcrumb data do not break line framing`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + val log = BreadcrumbAppendLog(options(), file) + + log.append( + listOf( + Breadcrumb.debug("first\nsecond\r\nthird").apply { setData("key", "a\nb") }, + Breadcrumb.debug("after"), + ) + ) + + assertThat(file.readLines().filter { it.isNotEmpty() }).hasSize(2) + assertThat(log.read().map { it.message }) + .containsExactly("first\nsecond\r\nthird", "after") + .inOrder() + } + + @Test + fun `tolerates a non-positive maxBreadcrumbs`() { + val file = File(tmpDir.newFolder(), "breadcrumbs.json") + val log = BreadcrumbAppendLog(options(maxBreadcrumbs = 0), file) + + log.append(listOf(Breadcrumb.debug("one"), Breadcrumb.debug("two"))) + + assertThat(log.read().map { it.message }).containsExactly("two") + } +} diff --git a/sentry/src/test/java/io/sentry/cache/BreadcrumbPersistenceBenchmark.kt b/sentry/src/test/java/io/sentry/cache/BreadcrumbPersistenceBenchmark.kt new file mode 100644 index 00000000000..c9cbb8dc8a0 --- /dev/null +++ b/sentry/src/test/java/io/sentry/cache/BreadcrumbPersistenceBenchmark.kt @@ -0,0 +1,152 @@ +package io.sentry.cache + +import io.sentry.Breadcrumb +import io.sentry.NoOpLogger +import io.sentry.SentryOptions +import io.sentry.cache.tape.ObjectQueue +import io.sentry.cache.tape.QueueFile +import java.io.BufferedWriter +import java.io.ByteArrayInputStream +import java.io.File +import java.io.InputStreamReader +import java.io.OutputStream +import java.io.OutputStreamWriter +import java.nio.file.Files +import kotlin.system.measureNanoTime +import kotlin.test.Ignore +import kotlin.test.Test + +/** + * Throwaway A/B harness comparing the JSONL append log against the tape QueueFile it replaces, each + * configured the way it is (or was) configured in production: tape with buffered writes plus one + * fsync per flush, JSONL with buffered writes and no fsync. + * + * Also measures tape with the fsync removed, which isolates how much of the difference is the fsync + * versus the ring-buffer bookkeeping — the two are easy to conflate. + * + * Ignored by default; drop the annotation and run `./gradlew :sentry:test + * --tests="*BreadcrumbPersistenceBenchmark*" -i` to see the numbers. + */ +@Ignore("manual benchmark, not a correctness test") +class BreadcrumbPersistenceBenchmark { + + private val options = + SentryOptions().apply { + setLogger(NoOpLogger.getInstance()) + maxBreadcrumbs = 100 + } + + private enum class Impl { + /** tape as PersistingScopeObserver configured it: buffered writes, one fsync per flush. */ + TAPE, + /** tape with the per-flush fsync removed, to separate fsync cost from bookkeeping cost. */ + TAPE_NO_FSYNC, + /** the JSONL append log, buffered and never fsync'd. */ + JSONL, + } + + @Test + fun `compare steady-state single-crumb flushes`() { + val flushes = 2_000 + report("steady state ($flushes flushes x 1 crumb)", flushes, 1) + } + + @Test + fun `compare startup-style batched flushes`() { + val flushes = 100 + report("startup ($flushes flushes x 20 crumbs)", flushes, 20) + } + + @Test + fun `compare reads of a full log`() { + val reads = 100 + reportRead("read ($reads reads of ${options.maxBreadcrumbs} crumbs)", reads) + } + + private fun crumbs(n: Int) = (1..n).map { Breadcrumb.debug("breadcrumb number $it") } + + private fun tapeQueue(file: File): ObjectQueue { + val queueFile = + QueueFile.Builder(file).size(options.maxBreadcrumbs).synchronousWrites(false).build() + return ObjectQueue.create( + queueFile, + object : ObjectQueue.Converter { + override fun from(source: ByteArray): Breadcrumb? = + InputStreamReader(ByteArrayInputStream(source), Charsets.UTF_8).use { + options.serializer.deserialize(it, Breadcrumb::class.java) + } + + override fun toStream(value: Breadcrumb, sink: OutputStream) { + BufferedWriter(OutputStreamWriter(sink, Charsets.UTF_8)).use { + options.serializer.serialize(value, it) + } + } + }, + ) + } + + private fun writeRun(impl: Impl, flushes: Int, perFlush: Int): Long { + val batch = crumbs(perFlush) + return when (impl) { + Impl.TAPE, + Impl.TAPE_NO_FSYNC -> { + val queue = tapeQueue(tmpFile()) + val fsync = impl == Impl.TAPE + measureNanoTime { + repeat(flushes) { + batch.forEach { queue.add(it) } + if (fsync) queue.sync() + } + } + .also { queue.close() } + } + Impl.JSONL -> { + val log = BreadcrumbAppendLog(options, tmpFile()) + measureNanoTime { repeat(flushes) { log.append(batch) } } + } + } + } + + private fun readRun(impl: Impl, reads: Int): Long { + val stored = crumbs(options.maxBreadcrumbs) + return when (impl) { + Impl.TAPE, + Impl.TAPE_NO_FSYNC -> { + val queue = tapeQueue(tmpFile()) + stored.forEach { queue.add(it) } + queue.sync() + measureNanoTime { repeat(reads) { queue.asList() } }.also { queue.close() } + } + Impl.JSONL -> { + val log = BreadcrumbAppendLog(options, tmpFile()) + log.append(stored) + measureNanoTime { repeat(reads) { log.read() } } + } + } + } + + private fun tmpFile(): File = + Files.createTempDirectory("bench").toFile().let { File(it, "breadcrumbs.json") } + + private fun report(label: String, flushes: Int, perFlush: Int) = + print(label) { writeRun(it, flushes, perFlush) } + + private fun reportRead(label: String, reads: Int) = print(label) { readRun(it, reads) } + + private fun print(label: String, run: (Impl) -> Long) { + // warm up the JIT and page cache before measuring + repeat(3) { Impl.entries.forEach { impl -> run(impl) } } + val best = Impl.entries.associateWith { impl -> (1..5).minOf { run(impl) } / 1_000_000.0 } + val summary = + Impl.entries.joinToString(" ") { "%s=%.2fms".format(it.name.lowercase(), best.getValue(it)) } + println( + "%-40s %s jsonl vs tape=%.2fx jsonl vs tape_no_fsync=%.2fx" + .format( + label, + summary, + best.getValue(Impl.TAPE) / best.getValue(Impl.JSONL), + best.getValue(Impl.TAPE_NO_FSYNC) / best.getValue(Impl.JSONL), + ) + ) + } +}