Skip to content

Temporary PR to help add debug code to diagnose concurrent read/write issue #1496

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

Closed
wants to merge 1 commit into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 10 additions & 1 deletion src/StackExchange.Redis/PhysicalBridge.cs
Original file line number Diff line number Diff line change
Expand Up @@ -733,9 +733,17 @@ internal WriteResult WriteMessageTakingWriteLockSync(PhysicalConnection physical

if (result == WriteResult.Success)
{
try
{
#pragma warning disable CS0618
result = physical.FlushSync(false, TimeoutMilliseconds);
result = physical.FlushSync(false, TimeoutMilliseconds);
#pragma warning restore CS0618
}
catch (InvalidOperationException ex) when (ex.Message.Contains("Concurrent reads or writes are not supported"))
{
// Throw with more detailed error information
throw TemporaryDebugHelper.CreateDetailedException($"{nameof(WriteMessageTakingWriteLockSync)}: token={token}, bridgeHashCode={GetHashCode()}, physicalConnectionHashCode={physical.GetHashCode()}", ex);
}
}

physical.SetIdle();
Expand Down Expand Up @@ -885,6 +893,7 @@ private void ProcessBacklog()
if (result == WriteResult.Success)
{
_backlogStatus = BacklogStatus.Flushing;

#pragma warning disable CS0618
result = physical.FlushSync(false, timeout);
#pragma warning restore CS0618
Expand Down
20 changes: 15 additions & 5 deletions src/StackExchange.Redis/PhysicalConnection.cs
Original file line number Diff line number Diff line change
Expand Up @@ -888,6 +888,7 @@ void ThrowTimeout()
#if DEBUG
if (millisecondsTimeout > _maxFlushTime) _maxFlushTime = millisecondsTimeout; // a fair bet even if we didn't measure
#endif
TemporaryDebugHelper.LastThrownFlushSyncTimeoutUtc = DateTime.UtcNow;
throw new TimeoutException("timeout while synchronously flushing");
}
}
Expand All @@ -903,15 +904,24 @@ internal ValueTask<WriteResult> FlushAsync(bool throwOnFailure)
long flushBytes = -1;
if (_ioPipe is SocketConnection sc) flushBytes = sc.GetCounters().BytesWaitingToBeSent;
#endif
var flush = tmp.FlushAsync();
if (!flush.IsCompletedSuccessfully) return FlushAsync_Awaited(this, flush, throwOnFailure
try
{
var flush = tmp.FlushAsync();
if (!flush.IsCompletedSuccessfully) return FlushAsync_Awaited(this, flush, throwOnFailure
#if DEBUG
, startFlush, flushBytes
, startFlush, flushBytes
#endif
);
);
#if DEBUG
RecordEndFlush(startFlush, flushBytes);
RecordEndFlush(startFlush, flushBytes);
#endif
}
catch (InvalidOperationException ex) when (ex.Message.Contains("Concurrent reads or writes are not supported"))
{
// Throw with more detailed error information
throw TemporaryDebugHelper.CreateDetailedException($"{nameof(FlushAsync)}: tmp.GetHashCode()={tmp.GetHashCode()}, physicalConnectionHashCode:{GetHashCode()}", ex);
}

_writeStatus = WriteStatus.Flushed;
UpdateLastWriteTime();
return new ValueTask<WriteResult>(WriteResult.Success);
Expand Down
25 changes: 25 additions & 0 deletions src/StackExchange.Redis/TemporaryDebugHelper.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,25 @@
using System;

namespace StackExchange.Redis
{
/// <summary>
/// Temporary class to help debug an issue, see https://github.com/StackExchange/StackExchange.Redis/issues/1438
/// </summary>
public static class TemporaryDebugHelper
{
/// <summary>
/// The last time a sync flush had timed out, if at all
/// </summary>
public static DateTime? LastThrownFlushSyncTimeoutUtc { get; set; }

/// <summary>
/// Create a new error to be thrown with extra debugging information included in its message
/// </summary>
public static InvalidOperationException CreateDetailedException(string additionalErrorInformation, Exception innerException)
{
var lastTimedOutAgo = LastThrownFlushSyncTimeoutUtc != null ? DateTime.UtcNow - LastThrownFlushSyncTimeoutUtc.Value : (TimeSpan?) null;

throw new InvalidOperationException($"Encountered error discussed on SE.Redis GitHub #1438 [{additionalErrorInformation} | LastThrownFlushSyncTimeoutUtc: {LastThrownFlushSyncTimeoutUtc} ({lastTimedOutAgo})]", innerException);
}
}
}