Skip to content

Conversation

@Flash0ver
Copy link
Member

@Flash0ver Flash0ver commented Aug 1, 2025

closed
superseded by #4425

Flash0ver and others added 30 commits April 30, 2025 13:09
@Flash0ver Flash0ver self-assigned this Aug 1, 2025
@Flash0ver Flash0ver added the Logs label Aug 1, 2025
Copy link

@cursor cursor bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: Logger Flush Timeout Issues

The Logger.Flush call in Hub.FlushAsync now unconditionally uses TimeSpan.Zero. This causes two issues:

  1. In debug builds, Debug.Assert(_addLock.IsSet) fails in StructuredLogBatchBuffer.FlushScope.Flush(TimeSpan timeout) if the timeout (e.g., TimeSpan.Zero) elapses before all Add operations complete, particularly during ungraceful shutdowns.
  2. For normal FlushAsync calls, using TimeSpan.Zero prevents waiting for pending log additions, potentially leading to data loss or race conditions. This is inconsistent with Hub.Dispose which uses Timeout.InfiniteTimeSpan for safe flushing.

src/Sentry/Internal/StructuredLogBatchBuffer.cs#L196-L197

private void Clear(int length)

src/Sentry/Internal/Hub.cs#L788-L789

{
Logger.Flush(TimeSpan.Zero);

Fix in Cursor Fix in Web

{
try
{
Logger.Flush(TimeSpan.Zero);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bug: Logger Flush Ignores Timeout Parameter

The FlushAsync method inconsistently applies its timeout parameter. Logger.Flush is hardcoded to TimeSpan.Zero, causing it to return immediately, while CurrentClient.FlushAsync correctly uses the provided timeout. This prevents the logger from gracefully flushing, leading to an incomplete or ungraceful overall flush operation.

Locations (1)
Fix in Cursor Fix in Web

@Flash0ver
Copy link
Member Author

@sentry review

Comment on lines 788 to +789
{
Logger.Flush(TimeSpan.Zero);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The choice to use TimeSpan.Zero for logger flush in FlushAsync is questionable. This means the logger flush will never wait and could return immediately without actually flushing logs, potentially causing data loss. Consider using a small timeout (e.g., TimeSpan.FromMilliseconds(100)) or a fraction of the main timeout to ensure logs are actually flushed while not blocking indefinitely.

Did we get this right? 👍 / 👎 to inform future reviews.

Comment on lines +150 to +154
/// <param name="timeout">A <see cref="TimeSpan"/> that represents the number of milliseconds to wait, or a <see cref="TimeSpan"/> that represents <see langword="-1"/> milliseconds to wait indefinitely.</param>
/// <exception cref="System.ArgumentOutOfRangeException"><paramref name="timeout"/> is a negative number other than <see langword="-1"/> milliseconds, which represents an infinite time-out -or- <paramref name="timeout"/> is greater than <see cref="int.MaxValue"/>.</exception>
internal void Wait(TimeSpan timeout)
{
var lockObj = _lockObj;
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The Wait(TimeSpan timeout) method calls CountdownEvent.Wait(timeout, CancellationToken.None) but doesn't handle or propagate the return value. According to .NET documentation, CountdownEvent.Wait returns false when the timeout expires. Callers have no way to know if the wait succeeded or timed out, which could lead to incorrect behavior in flush operations.

Did we get this right? 👍 / 👎 to inform future reviews.

Comment on lines 279 to 285

internal SentryLog[] Flush(TimeSpan timeout)
{
var lockObj = _lockObj;
if (lockObj is not null)
{
_scope.Wait();
_scope.Wait(timeout);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The FlushScope.Flush(TimeSpan timeout) method doesn't handle the case where _scope.Wait(timeout) times out. If the wait times out, the method continues to call ToArrayAndClear(), which could lead to data corruption if add operations are still in progress. The method should check if the wait succeeded before proceeding.

Did we get this right? 👍 / 👎 to inform future reviews.

Comment on lines 139 to 140
{
SwapActiveBuffer(buffer);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The timeout parameter is passed to CaptureLogs but there's an inconsistency where OnTimeoutExceeded still uses Timeout.InfiniteTimeSpan. This could lead to deadlocks if the buffer is in a bad state. Consider using the same timeout handling strategy consistently.

Did we get this right? 👍 / 👎 to inform future reviews.

Comment on lines 104 to 105
SwapActiveBuffer(buffer);
CaptureLogs(buffer);
CaptureLogs(buffer, Timeout.InfiniteTimeSpan);
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In the TryEnqueue method, when status is AddedLast, the flush operation uses Timeout.InfiniteTimeSpan which could cause the application to hang if there are threading issues. Consider using a reasonable timeout here as well to prevent potential deadlocks.

Did we get this right? 👍 / 👎 to inform future reviews.

@Flash0ver Flash0ver marked this pull request as draft August 1, 2025 11:35
Base automatically changed from feat/logs-microsoft-extensions-logging to feat/logs August 6, 2025 12:47
Base automatically changed from feat/logs to main August 7, 2025 12:09
@Flash0ver Flash0ver closed this Aug 9, 2025
@Flash0ver Flash0ver deleted the fix/logs-flush-on-terminating branch August 9, 2025 08:14
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants