-
-
Notifications
You must be signed in to change notification settings - Fork 451
Send logs in batches #4378
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: feat/logs-options
Are you sure you want to change the base?
Send logs in batches #4378
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -6,6 +6,9 @@ | |
import io.sentry.hints.Backfillable; | ||
import io.sentry.hints.DiskFlushNotification; | ||
import io.sentry.hints.TransactionEnd; | ||
import io.sentry.logger.ILoggerBatchProcessor; | ||
import io.sentry.logger.LoggerBatchProcessor; | ||
import io.sentry.logger.NoOpLoggerBatchProcessor; | ||
import io.sentry.protocol.Contexts; | ||
import io.sentry.protocol.DebugMeta; | ||
import io.sentry.protocol.SentryId; | ||
|
@@ -16,7 +19,6 @@ | |
import java.io.Closeable; | ||
import java.io.IOException; | ||
import java.util.ArrayList; | ||
import java.util.Arrays; | ||
import java.util.Collection; | ||
import java.util.Collections; | ||
import java.util.Comparator; | ||
|
@@ -36,6 +38,7 @@ public final class SentryClient implements ISentryClient { | |
private final @NotNull SentryOptions options; | ||
private final @NotNull ITransport transport; | ||
private final @NotNull SortBreadcrumbsByDate sortBreadcrumbsByDate = new SortBreadcrumbsByDate(); | ||
private final @NotNull ILoggerBatchProcessor loggerBatchProcessor; | ||
|
||
@Override | ||
public boolean isEnabled() { | ||
|
@@ -55,6 +58,11 @@ public SentryClient(final @NotNull SentryOptions options) { | |
|
||
final RequestDetailsResolver requestDetailsResolver = new RequestDetailsResolver(options); | ||
transport = transportFactory.create(options, requestDetailsResolver.resolve()); | ||
if (options.getExperimental().getLogs().isEnabled()) { | ||
loggerBatchProcessor = new LoggerBatchProcessor(options, this); | ||
} else { | ||
loggerBatchProcessor = NoOpLoggerBatchProcessor.getInstance(); | ||
} | ||
} | ||
|
||
private boolean shouldApplyScopeData( | ||
|
@@ -625,16 +633,15 @@ public void captureUserFeedback(final @NotNull UserFeedback userFeedback) { | |
return new SentryEnvelope(envelopeHeader, envelopeItems); | ||
} | ||
|
||
private @NotNull SentryEnvelope buildEnvelope( | ||
final @NotNull SentryLogEvents logEvents, final @Nullable TraceContext traceContext) { | ||
private @NotNull SentryEnvelope buildEnvelope(final @NotNull SentryLogEvents logEvents) { | ||
final List<SentryEnvelopeItem> envelopeItems = new ArrayList<>(); | ||
|
||
final SentryEnvelopeItem logItem = | ||
SentryEnvelopeItem.fromLogs(options.getSerializer(), logEvents); | ||
envelopeItems.add(logItem); | ||
|
||
final SentryEnvelopeHeader envelopeHeader = | ||
new SentryEnvelopeHeader(null, options.getSdkVersion(), traceContext); | ||
new SentryEnvelopeHeader(null, options.getSdkVersion(), null); | ||
|
||
return new SentryEnvelope(envelopeHeader, envelopeItems); | ||
} | ||
|
@@ -1018,17 +1025,17 @@ public void captureLog( | |
hint = new Hint(); | ||
} | ||
|
||
@Nullable TraceContext traceContext = null; | ||
if (scope != null) { | ||
final @Nullable ITransaction transaction = scope.getTransaction(); | ||
if (transaction != null) { | ||
traceContext = transaction.traceContext(); | ||
} else { | ||
final @NotNull PropagationContext propagationContext = | ||
TracingUtils.maybeUpdateBaggage(scope, options); | ||
traceContext = propagationContext.traceContext(); | ||
} | ||
} | ||
// @Nullable TraceContext traceContext = null; | ||
// if (scope != null) { | ||
// final @Nullable ITransaction transaction = scope.getTransaction(); | ||
// if (transaction != null) { | ||
// traceContext = transaction.traceContext(); | ||
// } else { | ||
// final @NotNull PropagationContext propagationContext = | ||
// TracingUtils.maybeUpdateBaggage(scope, options); | ||
// traceContext = propagationContext.traceContext(); | ||
// } | ||
// } | ||
|
||
if (logEvent != null) { | ||
logEvent = executeBeforeSendLog(logEvent, hint); | ||
|
@@ -1040,15 +1047,18 @@ public void captureLog( | |
.recordLostEvent(DiscardReason.BEFORE_SEND, DataCategory.LogItem); | ||
return; | ||
} | ||
|
||
loggerBatchProcessor.add(logEvent); | ||
} | ||
|
||
try { | ||
final @NotNull SentryEnvelope envelope = | ||
buildEnvelope(new SentryLogEvents(Arrays.asList(logEvent)), traceContext); | ||
hint.clear(); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Before we were passing the There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Yeah it might have some effect especially for Android but I haven't found a good way to pass the hint through the batch processor unless we hold on to it until it's been sent and even then which |
||
} | ||
|
||
hint.clear(); | ||
// TODO buffer | ||
sendEnvelope(envelope, hint); | ||
@Override | ||
public void captureBatchedLogEvents(final @NotNull SentryLogEvents logEvents) { | ||
try { | ||
final @NotNull SentryEnvelope envelope = buildEnvelope(logEvents); | ||
sendEnvelope(envelope, null); | ||
} catch (IOException e) { | ||
options.getLogger().log(SentryLevel.WARNING, e, "Capturing log failed."); | ||
} | ||
|
@@ -1307,6 +1317,7 @@ public void close(final boolean isRestarting) { | |
options.getLogger().log(SentryLevel.INFO, "Closing SentryClient."); | ||
try { | ||
flush(isRestarting ? 0 : options.getShutdownTimeoutMillis()); | ||
loggerBatchProcessor.close(isRestarting); | ||
transport.close(isRestarting); | ||
} catch (IOException e) { | ||
options | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,10 @@ | ||
package io.sentry.logger; | ||
|
||
import io.sentry.SentryLogEvent; | ||
import org.jetbrains.annotations.NotNull; | ||
|
||
public interface ILoggerBatchProcessor { | ||
void add(@NotNull SentryLogEvent event); | ||
|
||
void close(boolean isRestarting); | ||
} |
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -32,8 +32,8 @@ public LoggerApi(final @NotNull Scopes scopes) { | |
|
||
@Override | ||
public void trace(final @Nullable String message, final @Nullable Object... args) { | ||
// TODO SentryLevel.TRACE does not exists yet | ||
// log(SentryLevel.TRACE, message, args); | ||
// TODO SentryLevel.TRACE does not exists yet so we just report it as DEBUG for now | ||
log(SentryLevel.DEBUG, message, args); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I opted for this as a quick fix to get |
||
} | ||
|
||
@Override | ||
|
Original file line number | Diff line number | Diff line change | ||||||||||||||
---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
@@ -0,0 +1,101 @@ | ||||||||||||||||
package io.sentry.logger; | ||||||||||||||||
|
||||||||||||||||
import io.sentry.ISentryClient; | ||||||||||||||||
import io.sentry.ISentryLifecycleToken; | ||||||||||||||||
import io.sentry.SentryLogEvent; | ||||||||||||||||
import io.sentry.SentryLogEvents; | ||||||||||||||||
import io.sentry.SentryOptions; | ||||||||||||||||
import io.sentry.util.AutoClosableReentrantLock; | ||||||||||||||||
import java.util.ArrayList; | ||||||||||||||||
import java.util.List; | ||||||||||||||||
import java.util.Queue; | ||||||||||||||||
import java.util.concurrent.ConcurrentLinkedQueue; | ||||||||||||||||
import java.util.concurrent.Future; | ||||||||||||||||
import org.jetbrains.annotations.NotNull; | ||||||||||||||||
import org.jetbrains.annotations.Nullable; | ||||||||||||||||
|
||||||||||||||||
public final class LoggerBatchProcessor implements ILoggerBatchProcessor { | ||||||||||||||||
|
||||||||||||||||
public static final int FLUSH_AFTER_MS = 5000; | ||||||||||||||||
public static final int MAX_BATCH_SIZE = 100; | ||||||||||||||||
|
||||||||||||||||
private final @NotNull SentryOptions options; | ||||||||||||||||
private final @NotNull ISentryClient client; | ||||||||||||||||
private final @NotNull Queue<SentryLogEvent> queue; | ||||||||||||||||
private volatile @Nullable Future<?> scheduledFlush; | ||||||||||||||||
private static final @NotNull AutoClosableReentrantLock scheduleLock = | ||||||||||||||||
new AutoClosableReentrantLock(); | ||||||||||||||||
|
||||||||||||||||
public LoggerBatchProcessor( | ||||||||||||||||
final @NotNull SentryOptions options, final @NotNull ISentryClient client) { | ||||||||||||||||
this.options = options; | ||||||||||||||||
this.client = client; | ||||||||||||||||
this.queue = new ConcurrentLinkedQueue<>(); | ||||||||||||||||
} | ||||||||||||||||
|
||||||||||||||||
@Override | ||||||||||||||||
public void add(final @NotNull SentryLogEvent logEvent) { | ||||||||||||||||
queue.offer(logEvent); | ||||||||||||||||
maybeSchedule(false, false); | ||||||||||||||||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This means we're locking on every log event. I'll try to optimize this. Ideas:
|
||||||||||||||||
} | ||||||||||||||||
|
||||||||||||||||
@Override | ||||||||||||||||
public void close(final boolean isRestarting) { | ||||||||||||||||
if (isRestarting) { | ||||||||||||||||
maybeSchedule(true, true); | ||||||||||||||||
} else { | ||||||||||||||||
while (!queue.isEmpty()) { | ||||||||||||||||
flushBatch(); | ||||||||||||||||
} | ||||||||||||||||
} | ||||||||||||||||
} | ||||||||||||||||
|
||||||||||||||||
private void maybeSchedule(boolean forceSchedule, boolean immediately) { | ||||||||||||||||
try (final @NotNull ISentryLifecycleToken ignored = scheduleLock.acquire()) { | ||||||||||||||||
final @Nullable Future<?> latestScheduledFlush = scheduledFlush; | ||||||||||||||||
if (forceSchedule | ||||||||||||||||
|| latestScheduledFlush == null | ||||||||||||||||
|| latestScheduledFlush.isDone() | ||||||||||||||||
|| latestScheduledFlush.isCancelled()) { | ||||||||||||||||
final int flushAfterMs = immediately ? 0 : FLUSH_AFTER_MS; | ||||||||||||||||
scheduledFlush = options.getExecutorService().schedule(new BatchRunnable(), flushAfterMs); | ||||||||||||||||
} | ||||||||||||||||
} | ||||||||||||||||
} | ||||||||||||||||
|
||||||||||||||||
private void flush() { | ||||||||||||||||
flushInternal(); | ||||||||||||||||
try (final @NotNull ISentryLifecycleToken ignored = scheduleLock.acquire()) { | ||||||||||||||||
if (!queue.isEmpty()) { | ||||||||||||||||
maybeSchedule(true, false); | ||||||||||||||||
} | ||||||||||||||||
} | ||||||||||||||||
} | ||||||||||||||||
|
||||||||||||||||
private void flushInternal() { | ||||||||||||||||
flushBatch(); | ||||||||||||||||
if (queue.size() >= MAX_BATCH_SIZE) { | ||||||||||||||||
flushInternal(); | ||||||||||||||||
} | ||||||||||||||||
Comment on lines
+76
to
+79
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. There is no need for recursion, personally I would prefer
Suggested change
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This would mean we send out at most two batches at a time. The way it's implemented atm sends out as many full batches as are available and then maybe reschedules (depending on queue being empty). There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Ah I missed the while, sorry There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Yeah we can change it. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. But needs to be do ... while so we send out before having a full batch |
||||||||||||||||
} | ||||||||||||||||
|
||||||||||||||||
private void flushBatch() { | ||||||||||||||||
final @NotNull List<SentryLogEvent> logEvents = new ArrayList<>(MAX_BATCH_SIZE); | ||||||||||||||||
do { | ||||||||||||||||
final @Nullable SentryLogEvent logEvent = queue.poll(); | ||||||||||||||||
if (logEvent != null) { | ||||||||||||||||
logEvents.add(logEvent); | ||||||||||||||||
} | ||||||||||||||||
} while (!queue.isEmpty() && logEvents.size() < MAX_BATCH_SIZE); | ||||||||||||||||
|
||||||||||||||||
client.captureBatchedLogEvents(new SentryLogEvents(logEvents)); | ||||||||||||||||
} | ||||||||||||||||
|
||||||||||||||||
private class BatchRunnable implements Runnable { | ||||||||||||||||
|
||||||||||||||||
@Override | ||||||||||||||||
public void run() { | ||||||||||||||||
flush(); | ||||||||||||||||
} | ||||||||||||||||
} | ||||||||||||||||
} |
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,27 @@ | ||
package io.sentry.logger; | ||
|
||
import io.sentry.SentryLogEvent; | ||
import org.jetbrains.annotations.ApiStatus; | ||
import org.jetbrains.annotations.NotNull; | ||
|
||
@ApiStatus.Experimental | ||
public final class NoOpLoggerBatchProcessor implements ILoggerBatchProcessor { | ||
|
||
private static final NoOpLoggerBatchProcessor instance = new NoOpLoggerBatchProcessor(); | ||
|
||
private NoOpLoggerBatchProcessor() {} | ||
|
||
public static NoOpLoggerBatchProcessor getInstance() { | ||
return instance; | ||
} | ||
|
||
@Override | ||
public void add(@NotNull SentryLogEvent event) { | ||
// do nothing | ||
} | ||
|
||
@Override | ||
public void close(final boolean isRestarting) { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. just wondering, when is There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. When the SDK is being re-initialized. LMK if you need more explanation. |
||
// do nothing | ||
} | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
(maybe) Updating baggage should be done in
LoggerApi
to freeze it on the first event going out.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm not sure, I don't fully understand when it should be done.