From c5071174faa7c3244c732999e74ac33cd48f50ca Mon Sep 17 00:00:00 2001 From: "github-actions[bot]" <41898282+github-actions[bot]@users.noreply.github.com> Date: Thu, 26 Aug 2021 10:34:43 -0700 Subject: [PATCH] [release/6.0-rc1] [wasm] spread WS based timers over next 6 minutes to prevent heavy throttling (#58160) * spread WS based timers over next 6 minutes to prevent heavy throttling * wip * wip * fix * better assert description * exclude test from CI, because helix is headless * feedback * more Co-authored-by: Pavel Savara --- .../System.Net.WebSockets.Client.sln | 7 + .../tests/SendReceiveTest.cs | 6 +- .../tests/wasm/BrowserTimerThrottlingTest.cs | 181 +++++++++++++++++++++ .../System.Net.WebSockets.Client.Wasm.Tests.csproj | 66 ++++++++ .../System.Net.WebSockets.Client.Wasm.Tests.sln | 25 +++ src/libraries/tests.proj | 3 + src/mono/wasm/runtime/binding_support.js | 25 ++- src/mono/wasm/runtime/library_mono.js | 31 +++- 8 files changed, 334 insertions(+), 10 deletions(-) create mode 100644 src/libraries/System.Net.WebSockets.Client/tests/wasm/BrowserTimerThrottlingTest.cs create mode 100644 src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.csproj create mode 100644 src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.sln diff --git a/src/libraries/System.Net.WebSockets.Client/System.Net.WebSockets.Client.sln b/src/libraries/System.Net.WebSockets.Client/System.Net.WebSockets.Client.sln index 6c64c7d..a0efb29 100644 --- a/src/libraries/System.Net.WebSockets.Client/System.Net.WebSockets.Client.sln +++ b/src/libraries/System.Net.WebSockets.Client/System.Net.WebSockets.Client.sln @@ -19,6 +19,8 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "ref", "ref", "{A0314AC5-E49 EndProject Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "src", "src", "{6F9A42A0-A04B-4CD0-B8C9-9A728274C851}" EndProject +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "System.Net.WebSockets.Client.Wasm.Tests", "tests\wasm\System.Net.WebSockets.Client.Wasm.Tests.csproj", "{CA20532A-33B3-4DC0-92D2-EA6D7987D59F}" +EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|Any CPU = Debug|Any CPU @@ -53,6 +55,10 @@ Global {6B9721B2-00D0-41EC-96B9-6428CF1830CF}.Debug|Any CPU.Build.0 = Debug|Any CPU {6B9721B2-00D0-41EC-96B9-6428CF1830CF}.Release|Any CPU.ActiveCfg = Release|Any CPU {6B9721B2-00D0-41EC-96B9-6428CF1830CF}.Release|Any CPU.Build.0 = Release|Any CPU + {CA20532A-33B3-4DC0-92D2-EA6D7987D59F}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {CA20532A-33B3-4DC0-92D2-EA6D7987D59F}.Debug|Any CPU.Build.0 = Debug|Any CPU + {CA20532A-33B3-4DC0-92D2-EA6D7987D59F}.Release|Any CPU.ActiveCfg = Release|Any CPU + {CA20532A-33B3-4DC0-92D2-EA6D7987D59F}.Release|Any CPU.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE @@ -65,6 +71,7 @@ Global {0CD4C24D-7746-46F0-8D47-A396882B5468} = {6F9A42A0-A04B-4CD0-B8C9-9A728274C851} {8CD4D190-F656-4970-9AE9-4A9F8B30A2F8} = {6F9A42A0-A04B-4CD0-B8C9-9A728274C851} {59A23CAB-D098-495F-A467-74C7553FF5BB} = {6F9A42A0-A04B-4CD0-B8C9-9A728274C851} + {CA20532A-33B3-4DC0-92D2-EA6D7987D59F} = {BEE2F256-0489-4809-AB20-27ADB2D0E10C} EndGlobalSection GlobalSection(ExtensibilityGlobals) = postSolution SolutionGuid = {D91D7DC5-24CC-4716-A357-8170C4EB1C32} diff --git a/src/libraries/System.Net.WebSockets.Client/tests/SendReceiveTest.cs b/src/libraries/System.Net.WebSockets.Client/tests/SendReceiveTest.cs index f5d86df..b8b4159 100644 --- a/src/libraries/System.Net.WebSockets.Client/tests/SendReceiveTest.cs +++ b/src/libraries/System.Net.WebSockets.Client/tests/SendReceiveTest.cs @@ -255,12 +255,12 @@ namespace System.Net.WebSockets.Client.Tests "ReceiveAsync"), ex.Message); - Assert.Equal(WebSocketState.Aborted, cws.State); + Assert.True(WebSocketState.Aborted == cws.State, cws.State+" state when InvalidOperationException"); } else if (ex is WebSocketException) { // Multiple cases. - Assert.Equal(WebSocketState.Aborted, cws.State); + Assert.True(WebSocketState.Aborted == cws.State, cws.State + " state when WebSocketException"); WebSocketError errCode = (ex as WebSocketException).WebSocketErrorCode; Assert.True( @@ -269,7 +269,7 @@ namespace System.Net.WebSockets.Client.Tests } else if (ex is OperationCanceledException) { - Assert.Equal(WebSocketState.Aborted, cws.State); + Assert.True(WebSocketState.Aborted == cws.State, cws.State + " state when OperationCanceledException"); } else { diff --git a/src/libraries/System.Net.WebSockets.Client/tests/wasm/BrowserTimerThrottlingTest.cs b/src/libraries/System.Net.WebSockets.Client/tests/wasm/BrowserTimerThrottlingTest.cs new file mode 100644 index 0000000..df6e5f1 --- /dev/null +++ b/src/libraries/System.Net.WebSockets.Client/tests/wasm/BrowserTimerThrottlingTest.cs @@ -0,0 +1,181 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; +using System.Linq; +using System.Net.WebSockets.Client.Tests; +using System.Runtime.InteropServices; +using System.Text; +using System.Threading; +using System.Threading.Tasks; + +using Xunit; +using Xunit.Abstractions; +using Xunit.Sdk; + +namespace System.Net.WebSockets.Client.Wasm.Tests +{ + // https://developer.chrome.com/blog/timer-throttling-in-chrome-88/ + // https://docs.google.com/document/d/11FhKHRcABGS4SWPFGwoL6g0ALMqrFKapCk5ZTKKupEk/view + // requires chromium based browser + // requires minimized browser or browser tab out of focus, browser can't be headless + // requires --enable-features=IntensiveWakeUpThrottling:grace_period_seconds/1 chromeDriver flags + // doesn't work with --disable-background-timer-throttling + [TestCaseOrderer("System.Net.WebSockets.Client.Wasm.Tests.AlphabeticalOrderer", "System.Net.WebSockets.Client.Wasm.Tests")] + public class BrowserTimerThrottlingTest : ClientWebSocketTestBase + { + public static bool IsBrowser => RuntimeInformation.IsOSPlatform(OSPlatform.Create("BROWSER")); + const double moreThanLightThrottlingThreshold = 1900; + const double detectLightThrottlingThreshold = 900; + const double webSocketMessageFrequency = 45000; + const double fastTimeoutFrequency = 100; + + public BrowserTimerThrottlingTest(ITestOutputHelper output) : base(output) { } + + [ConditionalFact(nameof(PlatformDetection.IsBrowser))] + [OuterLoop] // involves long delay + // this test is influenced by usage of WS on the same browser tab in previous unit tests. we may need to wait long time for it to fizzle down + public async Task DotnetTimersAreHeavilyThrottledWithoutWebSocket() + { + double maxDelayMs = 0; + double maxLightDelayMs = 0; + DateTime start = DateTime.Now; + CancellationTokenSource cts = new CancellationTokenSource(); + + using (var timer = new Timers.Timer(fastTimeoutFrequency)) + { + DateTime last = DateTime.Now; + timer.AutoReset = true; + timer.Enabled = true; + timer.Elapsed += (object? source, Timers.ElapsedEventArgs? e) => + { + var ms = (e.SignalTime - last).TotalMilliseconds; + if (maxDelayMs < ms) + { + maxDelayMs = ms; + } + if (ms > moreThanLightThrottlingThreshold) + { +#if DEBUG + Console.WriteLine("Too slow tick " + ms); +#endif + // stop, we are throttled heavily, this is what we are looking for + cts.Cancel(); + } + else if (ms > detectLightThrottlingThreshold) + { + maxLightDelayMs = ms; + // we are lightly throttled +#if DEBUG + Console.WriteLine("Slow tick NO-WS " + ms); +#endif + } + last = e.SignalTime; + }; + + // test it for 10 minutes + try { await Task.Delay(10 * 60 * 1000, cts.Token); } catch (Exception) { } + timer.Close(); + } + Assert.True(maxDelayMs > detectLightThrottlingThreshold, "Expect that it throttled lightly " + maxDelayMs); + Assert.True(maxDelayMs > moreThanLightThrottlingThreshold, "Expect that it was heavily throttled " + maxDelayMs); + } + + [ConditionalFact(nameof(WebSocketsSupported), nameof(PlatformDetection.IsBrowser))] + [OuterLoop] // involves long delay + public async Task WebSocketKeepsDotnetTimersOnlyLightlyThrottled() + { + double maxDelayMs = 0; + double maxLightDelayMs = 0; + DateTime start = DateTime.Now; + CancellationTokenSource cts = new CancellationTokenSource(); + + using (ClientWebSocket cws = await WebSocketHelper.GetConnectedWebSocket(Test.Common.Configuration.WebSockets.RemoteEchoServer, TimeOutMilliseconds, _output)) + { + await SendAndReceive(cws, "test"); + using (var timer = new Timers.Timer(fastTimeoutFrequency)) + { + DateTime last = DateTime.Now; + DateTime lastSent = DateTime.MinValue; + timer.AutoReset = true; + timer.Enabled = true; + timer.Elapsed += async (object? source, Timers.ElapsedEventArgs? e) => + { + var ms = (e.SignalTime - last).TotalMilliseconds; + var msSent = (e.SignalTime - lastSent).TotalMilliseconds; + if (maxDelayMs < ms) + { + maxDelayMs = ms; + } + if (ms > moreThanLightThrottlingThreshold) + { + // fail fast, we are throttled heavily +#if DEBUG + Console.WriteLine("Too slow tick " + ms); +#endif + cts.Cancel(); + } + else if (ms > detectLightThrottlingThreshold) + { + maxLightDelayMs = ms; + // we are lightly throttled +#if DEBUG + Console.WriteLine("Slow tick WS " + ms); +#endif + } + if (msSent > webSocketMessageFrequency) + { + await SendAndReceive(cws, "test"); + lastSent = DateTime.Now; + } + last = e.SignalTime; + }; + + // test it for 10 minutes + try { await Task.Delay(10 * 60 * 1000, cts.Token); } catch (Exception) { } + timer.Close(); + } + await cws.CloseAsync(WebSocketCloseStatus.NormalClosure, "WebSocketKeepsDotnetTimersOnlyLightlyThrottled", CancellationToken.None); + } + Assert.True(maxDelayMs > detectLightThrottlingThreshold, "Expect that it throttled lightly " + maxDelayMs); + Assert.True(maxDelayMs < moreThanLightThrottlingThreshold, "Expect that it wasn't heavily throttled " + maxDelayMs); + } + + private async static Task SendAndReceive(ClientWebSocket cws, string message) + { + try + { + byte[] buffer = Encoding.UTF8.GetBytes(message); + await cws.SendAsync(new ArraySegment(buffer), WebSocketMessageType.Text, true, CancellationToken.None); + + var receiveBuffer = new byte[100]; + var receiveSegment = new ArraySegment(receiveBuffer); + WebSocketReceiveResult recvRet = await cws.ReceiveAsync(receiveSegment, CancellationToken.None); +#if DEBUG + Console.WriteLine("SendAndReceive"); +#endif + } + catch (OperationCanceledException) + { + } + catch (Exception ex) + { +#if DEBUG + Console.WriteLine("SendAndReceive fail:" + ex); +#endif + } + } + } + + // this is just for convinience, as the second test has side-effect to running page, the first test would take longer if they are in another order + public class AlphabeticalOrderer : ITestCaseOrderer + { + public IEnumerable OrderTestCases(IEnumerable testCases) + where TTestCase : ITestCase + { + List result = testCases.ToList(); + result.Sort((x, y) => StringComparer.Ordinal.Compare(x.TestMethod.Method.Name, y.TestMethod.Method.Name)); + return result; + } + } +} diff --git a/src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.csproj b/src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.csproj new file mode 100644 index 0000000..754539c --- /dev/null +++ b/src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.csproj @@ -0,0 +1,66 @@ + + + ../../src/Resources/Strings.resx + $(NetCoreAppCurrent)-Browser + $(DefineConstants);NETSTANDARD + + + + --background-throttling + WasmTestOnBrowser + $(TestArchiveRoot)browseronly/ + $(TestArchiveTestsRoot)$(OSPlatformConfig)/ + $(DefineConstants);TARGET_BROWSER + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + diff --git a/src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.sln b/src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.sln new file mode 100644 index 0000000..11f24af --- /dev/null +++ b/src/libraries/System.Net.WebSockets.Client/tests/wasm/System.Net.WebSockets.Client.Wasm.Tests.sln @@ -0,0 +1,25 @@ + +Microsoft Visual Studio Solution File, Format Version 12.00 +# Visual Studio Version 17 +VisualStudioVersion = 17.0.31521.260 +MinimumVisualStudioVersion = 10.0.40219.1 +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "System.Net.WebSockets.Client.Wasm.Tests", "System.Net.WebSockets.Client.Wasm.Tests.csproj", "{DA6DF153-169E-485D-90A4-EDBDA54B32A6}" +EndProject +Global + GlobalSection(SolutionConfigurationPlatforms) = preSolution + Debug|Any CPU = Debug|Any CPU + Release|Any CPU = Release|Any CPU + EndGlobalSection + GlobalSection(ProjectConfigurationPlatforms) = postSolution + {DA6DF153-169E-485D-90A4-EDBDA54B32A6}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {DA6DF153-169E-485D-90A4-EDBDA54B32A6}.Debug|Any CPU.Build.0 = Debug|Any CPU + {DA6DF153-169E-485D-90A4-EDBDA54B32A6}.Release|Any CPU.ActiveCfg = Release|Any CPU + {DA6DF153-169E-485D-90A4-EDBDA54B32A6}.Release|Any CPU.Build.0 = Release|Any CPU + EndGlobalSection + GlobalSection(SolutionProperties) = preSolution + HideSolutionNode = FALSE + EndGlobalSection + GlobalSection(ExtensibilityGlobals) = postSolution + SolutionGuid = {627DB5DF-DE31-44B4-B5FD-E5666467145E} + EndGlobalSection +EndGlobal diff --git a/src/libraries/tests.proj b/src/libraries/tests.proj index b5237fe..38fd8be 100644 --- a/src/libraries/tests.proj +++ b/src/libraries/tests.proj @@ -230,6 +230,9 @@ + + + diff --git a/src/mono/wasm/runtime/binding_support.js b/src/mono/wasm/runtime/binding_support.js index 6e2fb3c..11d50bf 100644 --- a/src/mono/wasm/runtime/binding_support.js +++ b/src/mono/wasm/runtime/binding_support.js @@ -160,6 +160,16 @@ var BindingSupportLib = { return Promise.resolve(js_obj) === js_obj || ((typeof js_obj === "object" || typeof js_obj === "function") && typeof js_obj.then === "function") }; + this.isChromium = false; + if (globalThis.navigator) { + var nav = globalThis.navigator; + if (nav.userAgentData && nav.userAgentData.brands) { + this.isChromium = nav.userAgentData.brands.some((i) => i.brand == 'Chromium'); + } + else if (globalThis.navigator.userAgent) { + this.isChromium = nav.userAgent.includes("Chrome"); + } + } this._empty_string = ""; this._empty_string_ptr = 0; @@ -372,7 +382,7 @@ var BindingSupportLib = { return this._wrap_delegate_gc_handle_as_function(gc_handle); }, - _wrap_delegate_gc_handle_as_function: function (gc_handle) { + _wrap_delegate_gc_handle_as_function: function (gc_handle, after_listener_callback) { this.bindings_lazy_init (); // see if we have js owned instance for this gc_handle already @@ -384,7 +394,11 @@ var BindingSupportLib = { result = function() { const delegateRoot = MONO.mono_wasm_new_root (BINDING.get_js_owned_object_by_gc_handle(gc_handle)); try { - return BINDING.call_method (result[BINDING.delegate_invoke_symbol], delegateRoot.value, result[BINDING.delegate_invoke_signature_symbol], arguments); + const res = BINDING.call_method(result[BINDING.delegate_invoke_symbol], delegateRoot.value, result[BINDING.delegate_invoke_signature_symbol], arguments); + if (after_listener_callback) { + after_listener_callback(); + } + return res; } finally { delegateRoot.release(); } @@ -2042,7 +2056,12 @@ var BindingSupportLib = { var obj = BINDING.mono_wasm_get_jsobj_from_js_handle(objHandle); if (!obj) throw new Error("ERR09: Invalid JS object handle for '"+sName+"'"); - var listener = BINDING._wrap_delegate_gc_handle_as_function(listener_gc_handle); + + const prevent_timer_throttling = !BINDING.isChromium || obj.constructor.name !== 'WebSocket' + ? null + : () => MONO.prevent_timer_throttling(0); + + var listener = BINDING._wrap_delegate_gc_handle_as_function(listener_gc_handle, prevent_timer_throttling); if (!listener) throw new Error("ERR10: Invalid listener gc_handle"); diff --git a/src/mono/wasm/runtime/library_mono.js b/src/mono/wasm/runtime/library_mono.js index 8f8d4cb..1e6fc31 100644 --- a/src/mono/wasm/runtime/library_mono.js +++ b/src/mono/wasm/runtime/library_mono.js @@ -52,6 +52,7 @@ var MonoSupportLib = { $MONO: { pump_count: 0, timeout_queue: [], + spread_timers_maximum:0, _vt_stack: [], mono_wasm_runtime_is_ready : false, mono_wasm_ignore_pdb_load_errors: true, @@ -74,6 +75,8 @@ var MonoSupportLib = { export_functions: function (module) { module ["pump_message"] = MONO.pump_message.bind(MONO); + module ["prevent_timer_throttling"] = MONO.prevent_timer_throttling.bind(MONO); + module ["mono_wasm_set_timeout_exec"] = MONO.mono_wasm_set_timeout_exec.bind(MONO); module ["mono_load_runtime_and_bcl"] = MONO.mono_load_runtime_and_bcl.bind(MONO); module ["mono_load_runtime_and_bcl_args"] = MONO.mono_load_runtime_and_bcl_args.bind(MONO); module ["mono_wasm_load_bytes_into_heap"] = MONO.mono_wasm_load_bytes_into_heap.bind(MONO); @@ -1457,6 +1460,28 @@ var MonoSupportLib = { } finally { Module.removeRunDependency(configFilePath); } + }, + mono_wasm_set_timeout_exec: function(id){ + if (!this.mono_set_timeout_exec) + this.mono_set_timeout_exec = Module.cwrap ("mono_set_timeout_exec", null, [ 'number' ]); + this.mono_set_timeout_exec (id); + }, + prevent_timer_throttling: function () { + // this will schedule timers every second for next 6 minutes, it should be called from WebSocket event, to make it work + // on next call, it would only extend the timers to cover yet uncovered future + let now = new Date().valueOf(); + const desired_reach_time = now + (1000 * 60 * 6); + const next_reach_time = Math.max(now + 1000, this.spread_timers_maximum); + const light_throttling_frequency = 1000; + for (var schedule = next_reach_time; schedule < desired_reach_time; schedule += light_throttling_frequency) { + const delay = schedule - now; + setTimeout(() => { + this.mono_wasm_set_timeout_exec(0); + MONO.pump_count++; + MONO.pump_message(); + }, delay); + } + this.spread_timers_maximum = desired_reach_time; } }, schedule_background_exec: function () { @@ -1467,17 +1492,15 @@ var MonoSupportLib = { }, mono_set_timeout: function (timeout, id) { - if (!this.mono_set_timeout_exec) - this.mono_set_timeout_exec = Module.cwrap ("mono_set_timeout_exec", null, [ 'number' ]); if (typeof globalThis.setTimeout === 'function') { globalThis.setTimeout (function () { - this.mono_set_timeout_exec (id); + MONO.mono_wasm_set_timeout_exec (id); }, timeout); } else { ++MONO.pump_count; MONO.timeout_queue.push(function() { - this.mono_set_timeout_exec (id); + MONO.mono_wasm_set_timeout_exec (id); }) } }, -- 2.7.4