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

tarekgh · 2021-11-24T18:32:51Z

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

The text was updated successfully, but these errors were encountered:

ghost · 2021-11-24T18:32:57Z

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:	-

ghost · 2021-11-24T18:37:01Z

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 · 2021-11-26T23:23:56Z

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 · 2021-11-26T23:40:56Z

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 · 2021-12-02T12:34:47Z

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

danmoseley · 2021-12-02T17:40:14Z

The test is untouched, my assumption is that clock_gettime (or clock_gettime_nsec_np) changed on Blazor (?)

danmoseley · 2021-12-02T17:40:39Z

@lewing may know.

lewing · 2021-12-02T18:56:56Z

The browser definitely has lower resolution than desktop but I'm also a bit unsure why it started failing recently. @pavelsavara any thoughts?

Issue: dotnet#62021

pavelsavara · 2021-12-02T19:05:24Z

We have new chrome, it may be the cause.
https://developer.chrome.com/blog/cross-origin-isolated-hr-timers/

Issue: dotnet#62021

pavelsavara · 2021-12-03T12:06:38Z

@radical could we close this one ?

radical · 2021-12-03T17:01:41Z

If we are good with the workaround, and won't be fixing it, then feel free to close the issue.

pavelsavara · 2021-12-03T18:25:25Z

There is also CLOCK_MONOTONIC feature in emscripten. I don't know much about it yet.
emscripten-core/emscripten#2761

Should we explore this topic further @lewing ?

radical · 2021-12-05T01:18:22Z

Another failure due to the same reason, IIUC:

[00:32:41] fail: [FAIL] System.Diagnostics.Tests.StopwatchTests.StartNewAndReset
[00:32:41] info: Assert.True() Failure
[00:32:41] info: Expected: True
[00:32:41] info: Actual:   False
[00:32:41] info:    at System.Diagnostics.Tests.StopwatchTests.StartNewAndReset()
[00:32:41] info:    at System.Reflection.RuntimeMethodInfo.InvokeWorker(Object obj, BindingFlags invokeAttr, Span`1 parameters)

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-62400-merge-731c7d739fe9436695/System.Runtime.Extensions.Tests/1/console.962c38b0.log?sv=2019-07-07&se=2021-12-25T00%3A01%3A26Z&sr=c&sp=rl&sig=63muZ%2BiSX5Pm0bcwz2%2Ba7oX5Rth1zzdcep6ib91CAI8%3D

…he (#62411) .. desktop. Earlier we did this for one test, but others are hitting this issue randomly too. New one: ``` [00:32:41] fail: [FAIL] System.Diagnostics.Tests.StopwatchTests.StartNewAndReset [00:32:41] info: Assert.True() Failure [00:32:41] info: Expected: True [00:32:41] info: Actual: False [00:32:41] info: at System.Diagnostics.Tests.StopwatchTests.StartNewAndReset() [00:32:41] info: at System.Reflection.RuntimeMethodInfo.InvokeWorker(Object obj, BindingFlags invokeAttr, Span`1 parameters) ``` Issue: #62021

dotnet-issue-labeler bot added area-System.Diagnostics untriaged New issue has not been triaged by the area owner labels Nov 24, 2021

tarekgh mentioned this issue Nov 24, 2021

Fix calling NLS with Cultures has alternative sort names #61992

Merged

This was referenced Nov 24, 2021

[Wasm] JS modularization #61313

Merged

[wasm] debug with modularized runtime(s) #61848

Merged

pavelsavara added the arch-wasm WebAssembly architecture label Nov 24, 2021

pavelsavara removed the untriaged New issue has not been triaged by the area owner label Nov 24, 2021

tommcdon added area-System.Diagnostics-mono and removed area-System.Diagnostics labels Nov 25, 2021

akoeplinger mentioned this issue Dec 2, 2021

[mono] Fix warnings with recent clang/gcc #62244

Merged

radical added a commit to radical/runtime that referenced this issue Dec 2, 2021

[wasm] Disable System.Diagnostics.Tests.StopwatchTests.GetTimestamp

7527d5f

Issue: dotnet#62021

radical mentioned this issue Dec 2, 2021

[wasm] Work around System.Diagnostics.Tests.StopwatchTests.GetTimestamp failure #62290

Merged

lewing assigned pavelsavara Dec 2, 2021

radical added a commit to radical/runtime that referenced this issue Dec 2, 2021

[wasm] StopwatchTests.GetTimestamp: sleep for 5ms on browser

35e253d

Issue: dotnet#62021

radical mentioned this issue Dec 5, 2021

[wasm] Work around the browser having a lower timer resolution than the #62411

Merged

pavelsavara added this to the Future milestone Jun 6, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

tarekgh commented Nov 24, 2021

ghost commented Nov 24, 2021

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

ghost commented Nov 24, 2021

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

danmoseley commented Nov 26, 2021

danmoseley commented Nov 26, 2021 •

edited

Loading

akoeplinger commented Dec 2, 2021

danmoseley commented Dec 2, 2021

danmoseley commented Dec 2, 2021

lewing commented Dec 2, 2021

pavelsavara commented Dec 2, 2021

pavelsavara commented Dec 3, 2021

radical commented Dec 3, 2021

pavelsavara commented Dec 3, 2021

radical commented Dec 5, 2021

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

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

Comments

tarekgh commented Nov 24, 2021

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

ghost commented Nov 24, 2021

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

ghost commented Nov 24, 2021

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

danmoseley commented Nov 26, 2021

danmoseley commented Nov 26, 2021 • edited Loading

akoeplinger commented Dec 2, 2021

danmoseley commented Dec 2, 2021

danmoseley commented Dec 2, 2021

lewing commented Dec 2, 2021

pavelsavara commented Dec 2, 2021

pavelsavara commented Dec 3, 2021

radical commented Dec 3, 2021

pavelsavara commented Dec 3, 2021

radical commented Dec 5, 2021

danmoseley commented Nov 26, 2021 •

edited

Loading