System.Runtime test suite does not always run the same number of tests #76285

kg · 2022-09-28T03:11:28Z

Description

When running the System.Runtime test suite under wasm the number of test cases executed appears to be random each time. This suggests we are not actually running the same set of tests every time on CI and this could lead to intermittent failures and bad coverage.

Reproduction Steps

./dotnet.sh build /t:Test /p:TargetOS=Browser /p:TargetArchitecture=wasm /p:Configuration=Release src/libraries/System.Runtime/tests/System.Runtime.Tests.csproj

Expected behavior

Same number of tests run every time

Actual behavior

Normal output:

  info: Discovered:  System.Runtime.Tests.dll (found 8929 of 9059 test cases)
  info: Using random seed for test cases: 405324687
  info: Using random seed for collections: 405324687
  info: Starting:    System.Runtime.Tests.dll
  info: Finished:    System.Runtime.Tests.dll
  info: 
  info: === TEST EXECUTION SUMMARY ===
  info: Total: 49999, Errors: 0, Failed: 0, Skipped: 91, Time: 148.383107s

Unusual output:

  info: Discovered:  System.Runtime.Tests.dll (found 8929 of 9059 test cases)
  info: Using random seed for test cases: 1326236753
  info: Using random seed for collections: 1326236753
  info: Starting:    System.Runtime.Tests.dll
  info: Finished:    System.Runtime.Tests.dll
  info: 
  info: === TEST EXECUTION SUMMARY ===
  info: Total: 50001, Errors: 0, Failed: 0, Skipped: 91, Time: 146.9656209s

I've personally seen 50000 and 50005 total tests as well.

Regression?

No response

Known Workarounds

No response

Configuration

Source build on Debian 10 x86-64 forked off 4e1ef10

Other information

Some other people on the team have also observed this with test counts like 50063. For me it usually is 49999 but I've seen lots of different numbers from run to run. This is probably caused by test order randomization somehow

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

ghost · 2022-09-28T03:11:36Z

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

Issue Details

Description

When running the System.Runtime test suite under wasm the number of test cases executed appears to be random each time. This suggests we are not actually running the same set of tests every time on CI and this could lead to intermittent failures and bad coverage.

Reproduction Steps

./dotnet.sh build /t:Test /p:TargetOS=Browser /p:TargetArchitecture=wasm /p:Configuration=Release src/libraries/System.Runtime/tests/System.Runtime.Tests.csproj

Expected behavior

Same number of tests run every time

Actual behavior

Normal output:

  info: Discovered:  System.Runtime.Tests.dll (found 8929 of 9059 test cases)
  info: Using random seed for test cases: 405324687
  info: Using random seed for collections: 405324687
  info: Starting:    System.Runtime.Tests.dll
  info: Finished:    System.Runtime.Tests.dll
  info: 
  info: === TEST EXECUTION SUMMARY ===
  info: Total: 49999, Errors: 0, Failed: 0, Skipped: 91, Time: 148.383107s

Unusual output:

  info: Discovered:  System.Runtime.Tests.dll (found 8929 of 9059 test cases)
  info: Using random seed for test cases: 1326236753
  info: Using random seed for collections: 1326236753
  info: Starting:    System.Runtime.Tests.dll
  info: Finished:    System.Runtime.Tests.dll
  info: 
  info: === TEST EXECUTION SUMMARY ===
  info: Total: 50001, Errors: 0, Failed: 0, Skipped: 91, Time: 146.9656209s

I've personally seen 50000 and 50005 total tests as well.

Regression?

No response

Known Workarounds

No response

Configuration

Source build on Debian 10 x86-64 forked off 4e1ef10

Other information

Some other people on the team have also observed this with test counts like 50063. For me it usually is 49999 but I've seen lots of different numbers from run to run. This is probably caused by test order randomization somehow

Author:	kg
Assignees:	-
Labels:	`area-Infrastructure-mono`
Milestone:	-

ghost · 2022-09-28T03:11:51Z

Tagging subscribers to this area: @dotnet/area-system-runtime
See info in area-owners.md if you want to be subscribed.

Issue Details

Description

When running the System.Runtime test suite under wasm the number of test cases executed appears to be random each time. This suggests we are not actually running the same set of tests every time on CI and this could lead to intermittent failures and bad coverage.

Reproduction Steps

./dotnet.sh build /t:Test /p:TargetOS=Browser /p:TargetArchitecture=wasm /p:Configuration=Release src/libraries/System.Runtime/tests/System.Runtime.Tests.csproj

Expected behavior

Same number of tests run every time

Actual behavior

Normal output:

  info: Discovered:  System.Runtime.Tests.dll (found 8929 of 9059 test cases)
  info: Using random seed for test cases: 405324687
  info: Using random seed for collections: 405324687
  info: Starting:    System.Runtime.Tests.dll
  info: Finished:    System.Runtime.Tests.dll
  info: 
  info: === TEST EXECUTION SUMMARY ===
  info: Total: 49999, Errors: 0, Failed: 0, Skipped: 91, Time: 148.383107s

Unusual output:

  info: Discovered:  System.Runtime.Tests.dll (found 8929 of 9059 test cases)
  info: Using random seed for test cases: 1326236753
  info: Using random seed for collections: 1326236753
  info: Starting:    System.Runtime.Tests.dll
  info: Finished:    System.Runtime.Tests.dll
  info: 
  info: === TEST EXECUTION SUMMARY ===
  info: Total: 50001, Errors: 0, Failed: 0, Skipped: 91, Time: 146.9656209s

I've personally seen 50000 and 50005 total tests as well.

Regression?

No response

Known Workarounds

No response

Configuration

Source build on Debian 10 x86-64 forked off 4e1ef10

Other information

Some other people on the team have also observed this with test counts like 50063. For me it usually is 49999 but I've seen lots of different numbers from run to run. This is probably caused by test order randomization somehow

Author:	kg
Assignees:	-
Labels:	`arch-wasm`, `area-System.Runtime`
Milestone:	-

radical · 2022-09-28T03:13:39Z

Comparing the results xml, the extra tests are:

System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC+01:00) Europe/Vatican)
System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC+01:00) Europe/Vatican)

stephentoub · 2023-04-17T12:35:16Z

On the same machine? The tests are fed theory inputs dynamically based on the OS:

runtime/src/libraries/System.Runtime/tests/System/TimeZoneInfoTests.cs

Line 2294 in e121d77

public static IEnumerable<object[]> SystemTimeZonesTestData()

The resulting number of tests run could legitimately differ if that theory ended up creating more or less test cases.

ilonatommy · 2024-06-03T10:43:29Z

This makes sense as we use GetSystemTimeZones. I don't think we can assure same time zones installed on test machines, @akoeplinger?

kg · 2024-06-03T18:17:59Z

This makes sense as we use GetSystemTimeZones.

Don't we deploy tzdb for wasm?

akoeplinger · 2024-06-05T14:53:06Z

Yeah. I don't see why that wouldn't be deterministic. We're bundling the timezone data from https://github.com/dotnet/runtime-assets/tree/main/src/System.Runtime.TimeZoneData into the wasm app, it doesn't read from the host.

@ilonatommy would you mind checking whether this still reproduces today?

ilonatommy · 2024-06-05T16:15:05Z

@ilonatommy would you mind checking whether this still reproduces today?

Yes and it's frequent
e.g. ST-WasmTestsOnFirefox:

ST-WasmTestsOnChrome:

ST-WasmTestOnV8

akoeplinger · 2024-06-05T17:04:43Z

I took a quick look at some of the files but I'm not convinced they're comparable, e.g. sometimes a test was removed/added because we're building different states of the repo. Another one is running with MonoAOT or agressive trimming and we disable some tests.

Can you try running locally on a stable config and see if you can repro there, like in the original issue?

ilonatommy · 2024-06-06T08:03:27Z

I believe that when test is disabled, then it should be in skipped section but still in the total count of discovered tests, so AOT/no-AOT should not matter. The only issue with this report might be different states of the lib on the PRs where tests were run.

Can you try running locally on a stable config and see if you can repro there, like in the original issue?

Sure, in 5 runs:

Tests run: 63979 Passed: 63877 Inconclusive: 0 Failed: 0 Ignored: 0 Skipped: 102
Tests run: 63981 Passed: 63879 Inconclusive: 0 Failed: 0 Ignored: 0 Skipped: 102
Tests run: 63979 Passed: 63877 Inconclusive: 0 Failed: 0 Ignored: 0 Skipped: 102
Tests run: 63979 Passed: 63877 Inconclusive: 0 Failed: 0 Ignored: 0 Skipped: 102
Tests run: 63979 Passed: 63877 Inconclusive: 0 Failed: 0 Ignored: 0 Skipped: 102

I didn't catch .xml for the 2nd run, I'll update when I'll get the diff of the testResults.
Edit:
Additional tests in Tests run: 63986:

"System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC+01:00) Europe/Vatican)"
"System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-05:00) America/Indianapolis)"
"System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Buenos_Aires)" 
"System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Catamarca)" 
"System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Cordoba)" 
"System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Jujuy)" 
"System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Mendoza)"

interestingly, additional tests in Tests run: 63991:

System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC-05:00) America/Indianapolis)
System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC-03:00) America/Buenos_Aires)
System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC-03:00) America/Catamarca)
System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC-03:00) America/Cordoba)
System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC-03:00) America/Jujuy)
System.Tests.TimeZoneInfoTests.TimeZoneInfo_DisplayNameStartsWithOffset(tzi: (UTC-03:00) America/Mendoza)
System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-05:00) America/Indianapolis)
System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Buenos_Aires)
System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Catamarca)
System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Cordoba)
System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Fortaleza)
System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Jujuy)
System.Tests.TimeZoneInfoTests.TimeZoneDisplayNames_Unix(timeZone: (UTC-03:00) America/Mendoza)

e.g. (UTC-03:00) America/Mendoza is additionally tested in one of the runs once but in the other twice. As if the number of available time zones varied between test methods in the same run.

Fixing <TimeZoneDataVersion>2020d</TimeZoneDataVersion> in the csproj does not change the situation.

Cleaning cache fixes it - we always get the same number of zones if we add ClearCachedData() in the beginning of GetSystemTimeZones method. The problem has to be connected with incorrect caching mechanism.

ilonatommy · 2024-06-06T09:19:59Z

~~Probably related: #96033~~ I don't think so anymore, the number of zones differs between two tests run as a part of the same test project, so they are using the same AppBundle

pavelsavara · 2024-07-04T14:24:35Z

The GetSystemTimeZones which is used in [MemberData(nameof(SystemTimeZonesTestData))] is enumerating the cache.

runtime/src/libraries/System.Private.CoreLib/src/System/TimeZoneInfo.cs

Lines 893 to 897 in aa9e4d3

    
           public static ReadOnlyCollection<TimeZoneInfo> GetSystemTimeZones(bool skipSorting) 
        
           { 
        
               CachedData cachedData = s_cachedData; 
        
               lock (cachedData)

And the cache is populated on the fly

runtime/src/libraries/System.Private.CoreLib/src/System/TimeZoneInfo.cs

Line 2126 in aa9e4d3

cachedData._systemTimeZones.Add(id, value!);

So that's why.

I wonder if public API GetSystemTimeZones should force-load all timezones from the machine.

ilonatommy · 2024-07-04T15:08:05Z

Explanation for the current logic:

runtime/src/libraries/System.Private.CoreLib/src/System/TimeZoneInfo.cs

Lines 2089 to 2095 in aa9e4d3

    
           // Fall back to reading from the local machine when the cache is not fully populated. 
        
           // On UNIX, there may be some tzfiles that aren't in the zones.tab file, and thus aren't returned from GetSystemTimeZones(). 
        
           // If a caller asks for one of these zones before calling GetSystemTimeZones(), the time zone is returned successfully. But if 
        
           // GetSystemTimeZones() is called first, FindSystemTimeZoneById will throw TimeZoneNotFoundException, which is inconsistent. 
        
           // To fix this, when 'alwaysFallbackToLocalMachine' is true, even if _allSystemTimeZonesRead is true, try reading the tzfile 
        
           // from disk, but don't add the time zone to the list returned from GetSystemTimeZones(). These time zones will only be 
        
           // available if asked for directly.

IIUC to force all time zones to land in cache we would need to know the IDs of these that are missing and because we can have more than one tz file, we cannot predict what IDs these would be.

pavelsavara · 2024-07-04T15:39:48Z

but on wasm we do know, we have just known set of TZs.
But this should also manifest on the other unix-like platforms, right ?

dotnet-issue-labeler bot added the area-Infrastructure-mono label Sep 28, 2022

ghost added the untriaged New issue has not been triaged by the area owner label Sep 28, 2022

kg added arch-wasm WebAssembly architecture and removed untriaged New issue has not been triaged by the area owner area-Infrastructure-mono labels Sep 28, 2022

kg added the area-System.Runtime label Sep 28, 2022

radical added this to the 8.0.0 milestone Sep 28, 2022

dakersnar mentioned this issue Nov 30, 2022

System.Runtime work planned for .NET 8 #79053

Closed

31 tasks

lewing modified the milestones: 8.0.0, 9.0.0 Jul 24, 2023

lewing modified the milestones: 9.0.0, 10.0.0 Jul 31, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

System.Runtime test suite does not always run the same number of tests #76285

System.Runtime test suite does not always run the same number of tests #76285

kg commented Sep 28, 2022

ghost commented Sep 28, 2022

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

ghost commented Sep 28, 2022

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

radical commented Sep 28, 2022

stephentoub commented Apr 17, 2023 •

edited

Loading

ilonatommy commented Jun 3, 2024

kg commented Jun 3, 2024

akoeplinger commented Jun 5, 2024 •

edited

Loading

ilonatommy commented Jun 5, 2024 •

edited

Loading

akoeplinger commented Jun 5, 2024 •

edited

Loading

ilonatommy commented Jun 6, 2024 •

edited

Loading

ilonatommy commented Jun 6, 2024 •

edited

Loading

pavelsavara commented Jul 4, 2024

ilonatommy commented Jul 4, 2024

pavelsavara commented Jul 4, 2024 •

edited

Loading

System.Runtime test suite does not always run the same number of tests #76285

System.Runtime test suite does not always run the same number of tests #76285

Comments

kg commented Sep 28, 2022

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

ghost commented Sep 28, 2022

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

ghost commented Sep 28, 2022

Description

Reproduction Steps

Expected behavior

Actual behavior

Regression?

Known Workarounds

Configuration

Other information

radical commented Sep 28, 2022

stephentoub commented Apr 17, 2023 • edited Loading

ilonatommy commented Jun 3, 2024

kg commented Jun 3, 2024

akoeplinger commented Jun 5, 2024 • edited Loading

ilonatommy commented Jun 5, 2024 • edited Loading

akoeplinger commented Jun 5, 2024 • edited Loading

ilonatommy commented Jun 6, 2024 • edited Loading

ilonatommy commented Jun 6, 2024 • edited Loading

pavelsavara commented Jul 4, 2024

ilonatommy commented Jul 4, 2024

pavelsavara commented Jul 4, 2024 • edited Loading

stephentoub commented Apr 17, 2023 •

edited

Loading

akoeplinger commented Jun 5, 2024 •

edited

Loading

ilonatommy commented Jun 5, 2024 •

edited

Loading

akoeplinger commented Jun 5, 2024 •

edited

Loading

ilonatommy commented Jun 6, 2024 •

edited

Loading

ilonatommy commented Jun 6, 2024 •

edited

Loading

pavelsavara commented Jul 4, 2024 •

edited

Loading