From 6a97debea2cbbc8c5393c3026e786c4e57b96658 Mon Sep 17 00:00:00 2001 From: Ilona Tomkowicz Date: Mon, 4 Mar 2024 16:47:28 +0100 Subject: [PATCH 1/3] New test with debug logs. --- .../Handlers/EchoWebSocketHandler.cs | 21 ++++++++++++ .../tests/CloseTest.cs | 32 +++++++++++++++++++ src/mono/browser/runtime/web-socket.ts | 5 +++ 3 files changed, 58 insertions(+) diff --git a/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs b/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs index 8304f2d1156072..429b26d0ed9d5d 100644 --- a/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs +++ b/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs @@ -144,6 +144,27 @@ await socket.CloseAsync( { await Task.Delay(5000); } + else if (receivedMessage == ".shutdownAfterTwoMessages") + { + byte[] buffer = new byte[1024]; + string message = DateTime.Now.ToString("HH:mm:ss"); + buffer = System.Text.Encoding.UTF8.GetBytes(message); + await socket.SendAsync( + new ArraySegment(buffer, 0, message.Length), + WebSocketMessageType.Text, + true, + CancellationToken.None); + await Task.Delay(1990); // try to sync with receive request from the client: 1.9k is too little, 2k too much + + message = DateTime.Now.ToString("HH:mm:ss"); + buffer = System.Text.Encoding.UTF8.GetBytes(message); + await socket.SendAsync( + new ArraySegment(buffer, 0, message.Length), + WebSocketMessageType.Text, + true, + CancellationToken.None); + await socket.CloseAsync(WebSocketCloseStatus.NormalClosure, receivedMessage, CancellationToken.None); + } else if (socket.State == WebSocketState.Open) { sendMessage = true; diff --git a/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs b/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs index c768fab5972a8a..403270f833c5a9 100644 --- a/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs +++ b/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs @@ -362,6 +362,38 @@ await cws.SendAsync( } } + + [ActiveIssue("https://github.com/dotnet/runtime/issues/28957", typeof(PlatformDetection), nameof(PlatformDetection.IsNotBrowser))] + [OuterLoop("Uses external servers", typeof(PlatformDetection), nameof(PlatformDetection.LocalEchoServerIsNotAvailable))] + [ConditionalTheory(nameof(WebSocketsSupported)), MemberData(nameof(EchoServers))] + public async Task CloseOutputAsync_ServerInitiated_CanSendRepeatedly(Uri server) + { + using (ClientWebSocket cws = await GetConnectedWebSocket(server, TimeOutMilliseconds, _output)) + { + var cts = new CancellationTokenSource(TimeOutMilliseconds); + + await cws.SendAsync( + WebSocketData.GetBufferFromText(".shutdownAfterTwoMessages"), + WebSocketMessageType.Text, + true, + cts.Token); + + var recvBuffer = new ArraySegment(new byte[1024]); + WebSocketReceiveResult recvResult = await cws.ReceiveAsync(recvBuffer, cts.Token); + var message = Encoding.UTF8.GetString(recvBuffer.ToArray(), 0, recvResult.Count); + Console.WriteLine($"Received: {message}"); + Assert.Equal(WebSocketState.Open, cws.State); + + await Task.Delay(2000); + + recvResult = await cws.ReceiveAsync(recvBuffer, cts.Token); + message = Encoding.UTF8.GetString(recvBuffer.ToArray(), 0, recvResult.Count); + Console.WriteLine($"2nd Received: {message}"); + await Task.Delay(1000); // otherwise it might be not closed yet + Assert.Equal(WebSocketState.Closed, cws.State); + } + } + [OuterLoop("Uses external servers", typeof(PlatformDetection), nameof(PlatformDetection.LocalEchoServerIsNotAvailable))] [ConditionalTheory(nameof(WebSocketsSupported)), MemberData(nameof(EchoServers))] public async Task CloseOutputAsync_CloseDescriptionIsNull_Success(Uri server) diff --git a/src/mono/browser/runtime/web-socket.ts b/src/mono/browser/runtime/web-socket.ts index 6c558938cface6..f70b8bf40d8acb 100644 --- a/src/mono/browser/runtime/web-socket.ts +++ b/src/mono/browser/runtime/web-socket.ts @@ -80,6 +80,7 @@ export function ws_wasm_create(uri: string, sub_protocols: string[] | null, rece }; const local_on_message = (ev: MessageEvent) => { try { + mono_log_warn("local_on_message triggered by " + ev.data.toString()); if (ws[wasm_ws_is_aborted]) return; if (!loaderHelpers.is_runtime_running()) return; if (WasmEnableThreads) { @@ -93,6 +94,7 @@ export function ws_wasm_create(uri: string, sub_protocols: string[] | null, rece }; const local_on_close = (ev: CloseEvent) => { try { + mono_log_warn("local_on_close triggered"); ws.removeEventListener("message", local_on_message); if (ws[wasm_ws_is_aborted]) return; if (!loaderHelpers.is_runtime_running()) return; @@ -212,6 +214,7 @@ export function ws_wasm_receive(ws: WebSocketExtension, buffer_ptr: VoidPtr, buf const receive_promise_queue = ws[wasm_ws_pending_receive_promise_queue]; if (receive_event_queue.getLength()) { + mono_log_warn("ws_wasm_receive message was sent before receive requested, processing message immediately"); mono_assert(receive_promise_queue.getLength() == 0, "ERR20: Invalid WS state"); web_socket_receive_buffering(ws, receive_event_queue, buffer_ptr, buffer_length); @@ -221,6 +224,7 @@ export function ws_wasm_receive(ws: WebSocketExtension, buffer_ptr: VoidPtr, buf const readyState = ws.readyState; if (readyState == WebSocket.CLOSED) { + mono_log_warn("ws_wasm_receive unsafe block of code reached, readyState == WebSocket.CLOSED"); const receive_status_ptr = ws[wasm_ws_receive_status_ptr]; setI32(receive_status_ptr, 0); // count setI32(receive_status_ptr + 4, 2); // type:close @@ -233,6 +237,7 @@ export function ws_wasm_receive(ws: WebSocketExtension, buffer_ptr: VoidPtr, buf receive_promise_control.buffer_ptr = buffer_ptr; receive_promise_control.buffer_length = buffer_length; receive_promise_queue.enqueue(receive_promise_control); + mono_log_warn("ws_wasm_receive receive requested before message arrived, waiting for message"); return promise; } From 1b3c156d072d3bd93b945efc31d1f881b8c6a3aa Mon Sep 17 00:00:00 2001 From: Ilona Tomkowicz Date: Mon, 4 Mar 2024 17:12:52 +0100 Subject: [PATCH 2/3] We should assert message, not state. --- .../NetCoreServer/Handlers/EchoWebSocketHandler.cs | 12 ++++++------ .../System.Net.WebSockets.Client/tests/CloseTest.cs | 7 ++----- 2 files changed, 8 insertions(+), 11 deletions(-) diff --git a/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs b/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs index 429b26d0ed9d5d..9e826d27efe04e 100644 --- a/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs +++ b/src/libraries/Common/tests/System/Net/Prerequisites/NetCoreServer/Handlers/EchoWebSocketHandler.cs @@ -147,19 +147,19 @@ await socket.CloseAsync( else if (receivedMessage == ".shutdownAfterTwoMessages") { byte[] buffer = new byte[1024]; - string message = DateTime.Now.ToString("HH:mm:ss"); - buffer = System.Text.Encoding.UTF8.GetBytes(message); + string message1 = $"{receivedMessage} 1 {DateTime.Now.ToString("HH:mm:ss")}"; + buffer = System.Text.Encoding.UTF8.GetBytes(message1); await socket.SendAsync( - new ArraySegment(buffer, 0, message.Length), + new ArraySegment(buffer, 0, message1.Length), WebSocketMessageType.Text, true, CancellationToken.None); await Task.Delay(1990); // try to sync with receive request from the client: 1.9k is too little, 2k too much - message = DateTime.Now.ToString("HH:mm:ss"); - buffer = System.Text.Encoding.UTF8.GetBytes(message); + string message2 = $"{receivedMessage} 2 {DateTime.Now.ToString("HH:mm:ss")}"; + buffer = System.Text.Encoding.UTF8.GetBytes(message2); await socket.SendAsync( - new ArraySegment(buffer, 0, message.Length), + new ArraySegment(buffer, 0, message2.Length), WebSocketMessageType.Text, true, CancellationToken.None); diff --git a/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs b/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs index 403270f833c5a9..4ca457c8633206 100644 --- a/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs +++ b/src/libraries/System.Net.WebSockets.Client/tests/CloseTest.cs @@ -381,16 +381,13 @@ await cws.SendAsync( var recvBuffer = new ArraySegment(new byte[1024]); WebSocketReceiveResult recvResult = await cws.ReceiveAsync(recvBuffer, cts.Token); var message = Encoding.UTF8.GetString(recvBuffer.ToArray(), 0, recvResult.Count); - Console.WriteLine($"Received: {message}"); - Assert.Equal(WebSocketState.Open, cws.State); + Assert.Contains(".shutdownAfterTwoMessages 1", message); await Task.Delay(2000); recvResult = await cws.ReceiveAsync(recvBuffer, cts.Token); message = Encoding.UTF8.GetString(recvBuffer.ToArray(), 0, recvResult.Count); - Console.WriteLine($"2nd Received: {message}"); - await Task.Delay(1000); // otherwise it might be not closed yet - Assert.Equal(WebSocketState.Closed, cws.State); + Assert.Contains(".shutdownAfterTwoMessages 2", message); } } From 4458d73a14109cdfe7c4bfaf9076a8cb7d8d0c32 Mon Sep 17 00:00:00 2001 From: Ilona Tomkowicz Date: Mon, 4 Mar 2024 17:25:50 +0100 Subject: [PATCH 3/3] Remove logging + fix debugging. --- src/mono/browser/runtime/web-socket.ts | 14 -------------- 1 file changed, 14 deletions(-) diff --git a/src/mono/browser/runtime/web-socket.ts b/src/mono/browser/runtime/web-socket.ts index f70b8bf40d8acb..bf00578c96be44 100644 --- a/src/mono/browser/runtime/web-socket.ts +++ b/src/mono/browser/runtime/web-socket.ts @@ -80,7 +80,6 @@ export function ws_wasm_create(uri: string, sub_protocols: string[] | null, rece }; const local_on_message = (ev: MessageEvent) => { try { - mono_log_warn("local_on_message triggered by " + ev.data.toString()); if (ws[wasm_ws_is_aborted]) return; if (!loaderHelpers.is_runtime_running()) return; if (WasmEnableThreads) { @@ -94,7 +93,6 @@ export function ws_wasm_create(uri: string, sub_protocols: string[] | null, rece }; const local_on_close = (ev: CloseEvent) => { try { - mono_log_warn("local_on_close triggered"); ws.removeEventListener("message", local_on_message); if (ws[wasm_ws_is_aborted]) return; if (!loaderHelpers.is_runtime_running()) return; @@ -214,7 +212,6 @@ export function ws_wasm_receive(ws: WebSocketExtension, buffer_ptr: VoidPtr, buf const receive_promise_queue = ws[wasm_ws_pending_receive_promise_queue]; if (receive_event_queue.getLength()) { - mono_log_warn("ws_wasm_receive message was sent before receive requested, processing message immediately"); mono_assert(receive_promise_queue.getLength() == 0, "ERR20: Invalid WS state"); web_socket_receive_buffering(ws, receive_event_queue, buffer_ptr, buffer_length); @@ -222,22 +219,11 @@ export function ws_wasm_receive(ws: WebSocketExtension, buffer_ptr: VoidPtr, buf return resolvedPromise(); } - const readyState = ws.readyState; - if (readyState == WebSocket.CLOSED) { - mono_log_warn("ws_wasm_receive unsafe block of code reached, readyState == WebSocket.CLOSED"); - const receive_status_ptr = ws[wasm_ws_receive_status_ptr]; - setI32(receive_status_ptr, 0); // count - setI32(receive_status_ptr + 4, 2); // type:close - setI32(receive_status_ptr + 8, 1);// end_of_message: true - return resolvedPromise(); - } - const { promise, promise_control } = createPromiseController(); const receive_promise_control = promise_control as ReceivePromiseControl; receive_promise_control.buffer_ptr = buffer_ptr; receive_promise_control.buffer_length = buffer_length; receive_promise_queue.enqueue(receive_promise_control); - mono_log_warn("ws_wasm_receive receive requested before message arrived, waiting for message"); return promise; }