System.Diagnostics.Tests.StopwatchTests.GetTimestamp test fails in the CI

[tarekgh]

Description

https://dev.azure.com/dnceng/public/_build/results?buildId=1483932&view=logs&jobId=108d2c4a-8a62-5a58-8dad-8e1042acc93c&j=108d2c4a-8a62-5a58-8dad-8e1042acc93c&t=568f884b-cc12-5fd3-e7fe-790b5ac403f4

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-61992-merge-7fb43d6a883f4488b6/System.Runtime.Extensions.Tests/1/console.767e6c7f.log?sv=2019-07-07&se=2021-12-14T02%3A29%3A30Z&sr=c&sp=rl&sig=z6v3ggZBbFYzzSs7RnkjjXGrSz8%2Fu01LaKM7xQ8zMAw%3D

[02:51:21] info: Incoming arguments: --run WasmTestRunner.dll System.Runtime.Extensions.Tests.dll -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
[02:51:21] info: Application arguments: --run WasmTestRunner.dll System.Runtime.Extensions.Tests.dll -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
[02:51:21] info: browser: Console websocket connected.
[02:51:22] info: Initializing.....
[02:51:23] info: Discovering: System.Runtime.Extensions.Tests.dll (method display = ClassAndMethod, method display options = None)
[02:51:24] info: Discovered:  System.Runtime.Extensions.Tests.dll (found 912 of 1000 test cases)
[02:51:24] info: Starting:    System.Runtime.Extensions.Tests.dll
[02:51:25] fail: [FAIL] System.Diagnostics.Tests.StopwatchTests.GetTimestamp
[02:51:25] info: Assert.NotEqual() Failure
[02:51:25] info: Expected: Not 4485599999
[02:51:25] info: Actual:   4485599999
[02:51:25] info:    at System.Diagnostics.Tests.StopwatchTests.GetTimestamp()
[02:51:25] info:    at System.Reflection.RuntimeMethodInfo.InvokeWorker(Object obj, BindingFlags invokeAttr, Span`1 parameters)
[02:51:51] info: Finished:    System.Runtime.Extensions.Tests.dll

Reproduction Steps

CI run

Expected behavior

No failures

Actual behavior

The test fails

Regression?

No response

Known Workarounds

No response

Configuration

No response

Other information

No response

Tagging subscribers to this area: @tommcdon
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Description

https://dev.azure.com/dnceng/public/_build/results?buildId=1483932&view=logs&jobId=108d2c4a-8a62-5a58-8dad-8e1042acc93c&j=108d2c4a-8a62-5a58-8dad-8e1042acc93c&t=568f884b-cc12-5fd3-e7fe-790b5ac403f4

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-61992-merge-7fb43d6a883f4488b6/System.Runtime.Extensions.Tests/1/console.767e6c7f.log?sv=2019-07-07&se=2021-12-14T02%3A29%3A30Z&sr=c&sp=rl&sig=z6v3ggZBbFYzzSs7RnkjjXGrSz8%2Fu01LaKM7xQ8zMAw%3D

[02:51:21] info: Incoming arguments: --run WasmTestRunner.dll System.Runtime.Extensions.Tests.dll -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
[02:51:21] info: Application arguments: --run WasmTestRunner.dll System.Runtime.Extensions.Tests.dll -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
[02:51:21] info: browser: Console websocket connected.
[02:51:22] info: Initializing.....
[02:51:23] info: Discovering: System.Runtime.Extensions.Tests.dll (method display = ClassAndMethod, method display options = None)
[02:51:24] info: Discovered:  System.Runtime.Extensions.Tests.dll (found 912 of 1000 test cases)
[02:51:24] info: Starting:    System.Runtime.Extensions.Tests.dll
[02:51:25] fail: [FAIL] System.Diagnostics.Tests.StopwatchTests.GetTimestamp
[02:51:25] info: Assert.NotEqual() Failure
[02:51:25] info: Expected: Not 4485599999
[02:51:25] info: Actual:   4485599999
[02:51:25] info:    at System.Diagnostics.Tests.StopwatchTests.GetTimestamp()
[02:51:25] info:    at System.Reflection.RuntimeMethodInfo.InvokeWorker(Object obj, BindingFlags invokeAttr, Span`1 parameters)
[02:51:51] info: Finished:    System.Runtime.Extensions.Tests.dll

Reproduction Steps

CI run

Expected behavior

No failures

Actual behavior

The test fails

Regression?

No response

Known Workarounds

No response

Configuration

No response

Other information

No response

Author:	tarekgh
Assignees:	-
Labels:	area-System.Diagnostics, untriaged
Milestone:	-

Tagging subscribers to 'arch-wasm': @lewing
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Description

https://dev.azure.com/dnceng/public/_build/results?buildId=1483932&view=logs&jobId=108d2c4a-8a62-5a58-8dad-8e1042acc93c&j=108d2c4a-8a62-5a58-8dad-8e1042acc93c&t=568f884b-cc12-5fd3-e7fe-790b5ac403f4

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-61992-merge-7fb43d6a883f4488b6/System.Runtime.Extensions.Tests/1/console.767e6c7f.log?sv=2019-07-07&se=2021-12-14T02%3A29%3A30Z&sr=c&sp=rl&sig=z6v3ggZBbFYzzSs7RnkjjXGrSz8%2Fu01LaKM7xQ8zMAw%3D

[02:51:21] info: Incoming arguments: --run WasmTestRunner.dll System.Runtime.Extensions.Tests.dll -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
[02:51:21] info: Application arguments: --run WasmTestRunner.dll System.Runtime.Extensions.Tests.dll -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
[02:51:21] info: browser: Console websocket connected.
[02:51:22] info: Initializing.....
[02:51:23] info: Discovering: System.Runtime.Extensions.Tests.dll (method display = ClassAndMethod, method display options = None)
[02:51:24] info: Discovered:  System.Runtime.Extensions.Tests.dll (found 912 of 1000 test cases)
[02:51:24] info: Starting:    System.Runtime.Extensions.Tests.dll
[02:51:25] fail: [FAIL] System.Diagnostics.Tests.StopwatchTests.GetTimestamp
[02:51:25] info: Assert.NotEqual() Failure
[02:51:25] info: Expected: Not 4485599999
[02:51:25] info: Actual:   4485599999
[02:51:25] info:    at System.Diagnostics.Tests.StopwatchTests.GetTimestamp()
[02:51:25] info:    at System.Reflection.RuntimeMethodInfo.InvokeWorker(Object obj, BindingFlags invokeAttr, Span`1 parameters)
[02:51:51] info: Finished:    System.Runtime.Extensions.Tests.dll

Reproduction Steps

CI run

Expected behavior

No failures

Actual behavior

The test fails

Regression?

No response

Known Workarounds

No response

Configuration

No response

Other information

No response

Author:	tarekgh
Assignees:	-
Labels:	arch-wasm, area-System.Diagnostics, untriaged
Milestone:	-

[danmoseley]

same in #61768

❌ System.Diagnostics.Tests.StopwatchTests.GetTimestamp [Details] [History] [Artifacts]
Exception Message
Assert.NotEqual() Failure
Expected: Not 8873699999
Actual:   8873699999
CallStack
   at System.Diagnostics.Tests.StopwatchTests.GetTimestamp()
   at System.Reflection.RuntimeMethodInfo.InvokeWorker(Object obj, BindingFlags invokeAttr, Span`1 parameters)
Pass Rate
Test has failed 7 out of 37212 runs (0.02%)
Failing Configuration
net7.0-Browser-Release-wasm-Mono_Release-wasmtestonbrowser-Ubuntu.1804.Amd64.Open

[danmoseley]

This means that this is getting called twice in approx 1ms and returning the same result. @lewing does Wasm have a larger quantum, or jitter? If so we should make the test sleep longer.

runtime/src/native/libs/System.Native/pal_time.c

Line 56 in 6f44dbe

uint64_t SystemNative_GetTimestamp()

runtime/src/libraries/System.Runtime.Extensions/tests/System/Diagnostics/Stopwatch.cs

Line 18 in 6f44dbe

Sleep();

[akoeplinger]

Also saw it in #62244, I wonder though why this started failing recently since the test is untouched since 2020.