Skip to content
Open
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
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
// Licensed to the .NET Foundation under one or more agreements.
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.
// See the LICENSE file in the project root for more information.

Expand Down Expand Up @@ -168,12 +168,9 @@ public static void WebSocket_Http_Duplex_Buffered(NetHttpMessageEncoding message
"The logging done by the Server was not returned via the Callback.");

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down Expand Up @@ -240,12 +237,9 @@ public static void WebSocket_Http_Duplex_Buffered_KeepAlive(NetHttpMessageEncodi
"The logging done by the Server was not returned via the Callback.");

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down Expand Up @@ -479,12 +473,9 @@ public static void WebSocket_Http_RequestReply_Streamed(NetHttpMessageEncoding m
}

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down Expand Up @@ -537,12 +528,9 @@ public static void WebSocket_Http_RequestReply_Buffered(NetHttpMessageEncoding m
}

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down Expand Up @@ -595,12 +583,9 @@ public static void WebSocket_Http_RequestReply_Buffered_KeepAlive(NetHttpMessage
}

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down Expand Up @@ -654,12 +639,9 @@ public static void WebSocket_Https_RequestReply_Buffered(NetHttpMessageEncoding
}

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down Expand Up @@ -715,12 +697,9 @@ public static void WebSocket_Https_RequestReply_Buffered_KeepAlive(NetHttpMessag
}

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down Expand Up @@ -885,12 +864,9 @@ public static void WebSocket_Http_VerifyWebSocketsUsed()
Assert.True(responseFromService, String.Format("Response from the service was not expected. Expected: 'True' but got {0}", responseFromService));

// *** CLEANUP *** \\
// Close the client and channel factory if not running on localhost. CoreWCF has a bug in Close method (on Linux).
if (!ScenarioTestHelpers.IsLocalHost())
{
((ICommunicationObject)client).Close();
channelFactory.Close();
}
// Close the client and channel factory.
((ICommunicationObject)client).Close();
channelFactory.Close();
}
finally
{
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,200 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.
// See the LICENSE file in the project root for more information.

#if NET
using System;
using System.Diagnostics;
using System.IO.Pipelines;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Connections;

namespace WcfService
{
// Diagnostics for the WebSocket Kestrel listeners on the SelfHostedCoreWcfService.
//
// Captures, in the Helix console log, the precise lifecycle of every TCP
// connection that reaches the WebSocket endpoints (ports 8083/8084):
// * timestamped open / close / exception events tagged [WSDIAG]
// * connection-id correlation with Kestrel trace logging
// * byte-level outbound sniffing on the IDuplexPipe transport so we can
// prove whether the server ever wrote a WebSocket Close frame (first
// byte 0x88 = FIN+opcode Close, unmasked server-to-client) before
// Kestrel's transport sent TCP FIN. This isolates whether the
// "remote party closed without completing the close handshake" race
// on Helix (issue #5818) is caused by a missing server-side Close
// frame or by a Kestrel teardown that races the close-frame flush.
internal sealed class WebSocketDiagnosticsConnectionMiddleware
{
internal const string Tag = "[WSDIAG]";
private static long s_seq;

private readonly ConnectionDelegate _next;
private readonly string _listener;

public WebSocketDiagnosticsConnectionMiddleware(ConnectionDelegate next, string listener)
{
_next = next;
_listener = listener;
}

public async Task OnConnectionAsync(ConnectionContext connection)
{
long n = Interlocked.Increment(ref s_seq);
Stopwatch sw = Stopwatch.StartNew();
string connId = connection.ConnectionId;
string remote = connection.RemoteEndPoint?.ToString() ?? "?";
string local = connection.LocalEndPoint?.ToString() ?? "?";

Write($"open #{n} listener={_listener} id={connId} remote={remote} local={local}");

IDuplexPipe original = connection.Transport;
SniffingDuplexPipe sniff = new SniffingDuplexPipe(original, connId, n, sw);
connection.Transport = sniff;

CancellationTokenRegistration ctr = connection.ConnectionClosed.Register(() =>
{
Write($"connclosed-token #{n} id={connId} elapsedMs={sw.ElapsedMilliseconds} {sniff.SummaryLine()}");
});

try
{
await _next(connection);
Write($"pipeline-completed #{n} id={connId} elapsedMs={sw.ElapsedMilliseconds} {sniff.SummaryLine()}");
}
catch (Exception ex)
{
Write($"pipeline-exception #{n} id={connId} elapsedMs={sw.ElapsedMilliseconds} type={ex.GetType().FullName} msg={Sanitize(ex.Message)}");
Write($"pipeline-exception-stack #{n} id={connId} {Sanitize(ex.ToString())}");
throw;
}
finally
{
ctr.Dispose();
Write($"close #{n} id={connId} totalMs={sw.ElapsedMilliseconds} {sniff.SummaryLine()}");
}
}

internal static void Write(string line)
{
Console.WriteLine($"{Tag} {DateTime.UtcNow:HH:mm:ss.fffffff} {line}");
}

private static string Sanitize(string s) =>
s is null ? string.Empty : s.Replace("\r", " ").Replace("\n", " | ");
}

// Wraps the connection's IDuplexPipe so we can observe outbound bytes
// written by the application. We do not modify any bytes; we only
// timestamp + log opcode bytes of each outbound write so we can prove
// whether a WebSocket Close frame was emitted before the socket's send
// loop completed.
internal sealed class SniffingDuplexPipe : IDuplexPipe
{
private readonly SniffingPipeWriter _output;
private readonly IDuplexPipe _inner;

public SniffingDuplexPipe(IDuplexPipe inner, string connId, long seq, Stopwatch sw)
{
_inner = inner;
_output = new SniffingPipeWriter(inner.Output, connId, seq, sw);
}

public PipeReader Input => _inner.Input;
public PipeWriter Output => _output;

public string SummaryLine() => _output.SummaryLine();
}

internal sealed class SniffingPipeWriter : PipeWriter
{
private readonly PipeWriter _inner;
private readonly string _connId;
private readonly long _seq;
private readonly Stopwatch _sw;

private Memory<byte> _lastMemory;
private long _totalBytes;
private int _writeCount;
private bool _closeFrameSeen;
private long _closeFrameElapsedMs = -1;
private byte _lastFirstByte;

public SniffingPipeWriter(PipeWriter inner, string connId, long seq, Stopwatch sw)
{
_inner = inner;
_connId = connId;
_seq = seq;
_sw = sw;
}

private void Inspect(ReadOnlySpan<byte> span, string source)
{
if (span.Length == 0) return;

_writeCount++;
_totalBytes += span.Length;
_lastFirstByte = span[0];

// Server-to-client frames are unmasked. WebSocket frame header
// byte layout: FIN(1) RSV(3) Opcode(4). Close opcode = 0x8.
// FIN+Close => 0x88.
if ((span[0] & 0x0F) == 0x08 && (span[0] & 0x80) == 0x80)
{
if (!_closeFrameSeen)
{
_closeFrameSeen = true;
_closeFrameElapsedMs = _sw.ElapsedMilliseconds;
int dumpLen = Math.Min(span.Length, 16);
string hex = Convert.ToHexString(span.Slice(0, dumpLen));
WebSocketDiagnosticsConnectionMiddleware.Write(
$"out-close-frame #{_seq} id={_connId} via={source} elapsedMs={_closeFrameElapsedMs} firstByte=0x{span[0]:X2} dump={hex}");
}
}
}

public override void Advance(int bytes)
{
if (bytes > 0 && _lastMemory.Length >= bytes)
{
Inspect(_lastMemory.Span.Slice(0, bytes), "GetMemory+Advance");
}
_inner.Advance(bytes);
}

public override Memory<byte> GetMemory(int sizeHint = 0)
{
_lastMemory = _inner.GetMemory(sizeHint);
return _lastMemory;
}

public override Span<byte> GetSpan(int sizeHint = 0)
{
_lastMemory = _inner.GetMemory(sizeHint);
return _lastMemory.Span;
}

public override ValueTask<FlushResult> WriteAsync(ReadOnlyMemory<byte> source, CancellationToken cancellationToken = default)
{
Inspect(source.Span, "WriteAsync");
return _inner.WriteAsync(source, cancellationToken);
}

public override ValueTask<FlushResult> FlushAsync(CancellationToken cancellationToken = default)
=> _inner.FlushAsync(cancellationToken);

public override void CancelPendingFlush() => _inner.CancelPendingFlush();

public override void Complete(Exception exception = null)
{
WebSocketDiagnosticsConnectionMiddleware.Write(
$"output-complete #{_seq} id={_connId} elapsedMs={_sw.ElapsedMilliseconds} totalBytes={_totalBytes} writes={_writeCount} closeFrameSent={_closeFrameSeen} ex={exception?.GetType().Name ?? "null"}");
_inner.Complete(exception);
}

public string SummaryLine() =>
$"writes={_writeCount} totalBytes={_totalBytes} closeFrameSent={_closeFrameSeen} closeFrameElapsedMs={_closeFrameElapsedMs} lastFirstByte=0x{_lastFirstByte:X2}";
}
}
#endif
Original file line number Diff line number Diff line change
Expand Up @@ -82,17 +82,34 @@ internal static async Task<IHost> StartHosts(bool useWebSocket)
builder.Logging.AddFilter("Microsoft", LogLevel.Debug);
builder.Logging.SetMinimumLevel(LogLevel.Debug);

// Diagnostics for WebSocket close-handshake race on Helix Linux (issue #5818).
// Capture connection lifecycle, raw TCP byte counts + FIN/RST events, and
// WebSocket close-frame events in the SelfHostedCoreWCFService stdout so they
// surface in the Helix console log next to the test failure.
if (useWebSocket)
{
builder.Logging.AddFilter("Microsoft.AspNetCore.Server.Kestrel", LogLevel.Trace);
builder.Logging.AddFilter("Microsoft.AspNetCore.Server.Kestrel.Connections", LogLevel.Trace);
builder.Logging.AddFilter("Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets", LogLevel.Trace);
builder.Logging.AddFilter("Microsoft.AspNetCore.WebSockets", LogLevel.Trace);
builder.Logging.AddFilter("CoreWCF", LogLevel.Trace);
}

builder.WebHost.ConfigureKestrel(options =>
{
options.AllowSynchronousIO = true;

if (useWebSocket)
{
options.Listen(IPAddress.IPv6Any, new Uri(BaseAddresses[ServiceSchema.WS]).Port);
options.Listen(IPAddress.IPv6Any, new Uri(BaseAddresses[ServiceSchema.WS]).Port, listenOptions =>
{
listenOptions.Use(next => new WebSocketDiagnosticsConnectionMiddleware(next, "ws-http").OnConnectionAsync);
});
options.Listen(IPAddress.IPv6Any, new Uri(BaseAddresses[ServiceSchema.WSS]).Port, listenOptions =>
{
X509Certificate2 cert = TestHost.CertificateFromFriendlyName(StoreName.My, StoreLocation.LocalMachine, "WCF Bridge - Machine certificate generated by the CertificateManager");
listenOptions.UseHttps(cert);
listenOptions.Use(next => new WebSocketDiagnosticsConnectionMiddleware(next, "ws-https").OnConnectionAsync);

if (Debugger.IsAttached)
{
Expand Down
Loading