Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Test failure JIT\\superpmi\\superpmicollect\\superpmicollect.cmd #90711

Closed
v-wenyuxu opened this issue Aug 17, 2023 · 17 comments · Fixed by #90888
Closed

Test failure JIT\\superpmi\\superpmicollect\\superpmicollect.cmd #90711

v-wenyuxu opened this issue Aug 17, 2023 · 17 comments · Fixed by #90888
Assignees
Labels
area-CodeGen-coreclr CLR JIT compiler in src/coreclr/src/jit and related components such as SuperPMI blocking-outerloop Blocking the 'runtime-coreclr outerloop' and 'runtime-libraries-coreclr outerloop' runs
Milestone

Comments

@v-wenyuxu
Copy link

v-wenyuxu commented Aug 17, 2023

Failed in: runtime-coreclr jitstress 20230815.1

Failed tests:

coreclr windows x86 Checked jitstress2_tiered @ Windows.10.Amd64.Open
    - JIT\\superpmi\\superpmicollect\\superpmicollect.cmd

Error message:

minkernel\crts\ucrt\inc\corecrt_internal_stdio_output.h(1690) : Assertion failed: ("Incorrect format specifier", 0)
ERROR: Test C:\h\w\AC2A0925\w\ACDC09A0\e\JIT\superpmi\superpmicollect\Bytemark\Bytemark.cmd failed

Return code:      1
Raw output file:      C:\h\w\AC2A0925\w\ACDC09A0\uploads\Reports\JIT.superpmi\superpmicollect\superpmicollect.output.txt
Raw output:
BEGIN EXECUTION
 "C:\h\w\AC2A0925\p\corerun.exe" -p "System.Reflection.Metadata.MetadataUpdater.IsSupported=false" -p "System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true"  superpmicollect.dll 
SuperPMI collection and playback - BEGIN
Setting environment variables:
    SuperPMIShimLogPath=C:\h\w\AC2A0925\t\b5x0svar.zn5SPMI
    SuperPMIShimPath=C:\h\w\AC2A0925\p\clrjit.dll
    DOTNET_JitName=superpmi-shim-collector.dll
Running: C:\Windows\system32\cmd.exe /c C:\h\w\AC2A0925\w\ACDC09A0\e\JIT\superpmi\superpmicollect\Bytemark\Bytemark.cmd
BEGIN EXECUTION
 "C:\h\w\AC2A0925\p\corerun.exe" -p "System.Reflection.Metadata.MetadataUpdater.IsSupported=false" -p "System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true"  Bytemark.dll 
BBBBBB   YYY   Y  TTTTTTT  EEEEEEE
BBB   B  YYY   Y    TTT    EEE
BBB   B  YYY   Y    TTT    EEE
BBBBBB    YYY Y     TTT    EEEEEEE
BBB   B    YYY      TTT    EEE
BBB   B    YYY      TTT    EEE
BBBBBB     YYY      TTT    EEEEEEE

BYTEmark (tm) C# Mode Benchmark ver. 2 (06/99)
NUMERIC SORT(jagged):  Iterations/sec: 984.53581  Index: 25.24904
NUMERIC SORT(rectangle):  Iterations/sec: 674.65136  Index: 17.30186
STRING SORT:  Iterations/sec: 5259.85300  Index: 2350.24710
BITFIELD:  Iterations/sec: 249331402.35652  Index: 42.76914
FP EMULATION(struct):  Iterations/sec: 126.60000  Index: 60.74856
FP EMULATION(class):  Iterations/sec: 129.60000  Index: 62.18810
FOURIER:  Iterations/sec: 11123.96726  Index: 12.65125
ASSIGNMENT(jagged):Expected: 100
Actual: -1073740791
END EXECUTION - FAILED
FAILED
SuperPMI collection and playback - FAILED
Expected: 100
Actual: 101
END EXECUTION - FAILED
FAILED
Test failed. Trying to see if dump file was created in C:\cores since 8/16/2023 5:53:46 AM
Processing C:\cores\corerun.exe.4552.dmp
Invoking: C:\Program Files (x86)\Windows Kits\10\Debuggers\x86\cdb.exe -c "$<C:\h\w\AC2A0925\t\tmphit0yx.tmp" -z "C:\cores\corerun.exe.4552.dmp"
stdout: 
Microsoft (R) Windows Debugger Version 10.0.18362.1 X86
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [C:\cores\corerun.exe.4552.dmp]
User Mini Dump File with Full Memory: Only application data is available


************* Path validation summary **************
Response                         Time (ms)     Location
OK                                             C:\h\w\AC2A0925\p\PDB
Symbol search path is: C:\h\w\AC2A0925\p\PDB
Executable search path is: 
Windows 10 Version 14393 MP (4 procs) Free x86 compatible
Product: Server, suite: TerminalServer DataCenter SingleUserTS
10.0.14393.5125 (rs1_release.220429-1732)
Machine Name:
Debug session time: Wed Aug 16 05:54:54.000 2023 (UTC + 0:00)
System Uptime: 0 days 0:05:20.414
Process Uptime: 0 days 0:01:05.000
.................................

************* Symbol Loading Error Summary **************
Module name            Error
ntdll                  The system cannot find the file specified

You can troubleshoot most symbol related issues by turning on symbol loading diagnostics (!sym noisy) and repeating the command that caused symbols to be loaded.
You should also verify that your symbol search path (.sympath) is correct.
This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(11c8.dc4): Security check failure or stack buffer overrun - code c0000409 (first/second chance not available)
For analysis of this file, run !analyze -v
*** WARNING: Unable to verify checksum for superpmi-shim-collector.dll
eax=00000001 ebx=04a26260

Stack trace:

   at JIT_superpmi._superpmicollect_superpmicollect_._superpmicollect_superpmicollect_cmd()
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(Object obj, IntPtr* args)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
Queued Pipeline Pipeline_Configuration OS Arch Test Outcome Properties BuildReason
2023-08-16T11:01:49.338Z runtime-coreclr outerloop Checked osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"System.PhaseName":"run_test_p1__osx_x64_checked","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","Project":"public","System.JobName":"__default","BuildNumber":"20230816.1","Reason":"Schedule","DefinitionName":"runtime-coreclr outerloop","configuration":"Checked","AzurePipelinesTestRunId":"7993004","System.PhaseAttempt":"1","architecture":"x64","DefinitionId":"108","CollectionUri":"https://dev.azure.com/dnceng-public/","System.StageName":"Build","BuildId":"375642","operatingSystem":"OSX.1200.Amd64.Open","System.JobAttempt":"1","System.StageAttempt":"1"} Schedule
2023-08-16T11:01:49.338Z runtime-coreclr outerloop Checked osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"System.PhaseName":"run_test_p1__osx_x64_checked","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","Project":"public","System.JobName":"__default","BuildNumber":"20230816.1","Reason":"Schedule","DefinitionName":"runtime-coreclr outerloop","configuration":"Checked","AzurePipelinesTestRunId":"7993004","System.PhaseAttempt":"1","architecture":"x64","DefinitionId":"108","CollectionUri":"https://dev.azure.com/dnceng-public/","System.StageName":"Build","BuildId":"375642","operatingSystem":"OSX.1200.Amd64.Open","System.JobAttempt":"1","System.StageAttempt":"1"} Schedule
2023-08-16T11:01:49.338Z runtime-coreclr outerloop Checked osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"System.PhaseName":"run_test_p1__osx_x64_checked","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","Project":"public","System.JobName":"__default","BuildNumber":"20230816.1","Reason":"Schedule","DefinitionName":"runtime-coreclr outerloop","configuration":"Checked","AzurePipelinesTestRunId":"7993004","System.PhaseAttempt":"1","architecture":"x64","DefinitionId":"108","CollectionUri":"https://dev.azure.com/dnceng-public/","System.StageName":"Build","BuildId":"375642","operatingSystem":"OSX.1200.Amd64.Open","System.JobAttempt":"1","System.StageAttempt":"1"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
More failures
Queued Pipeline Pipeline_Configuration OS Arch Test Outcome Properties BuildReason
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-08-05T06:00:45.852Z runtime-coreclr jitstress Checked-jitstress1_tiered osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildNumber":"20230804.1","System.JobAttempt":"1","AzurePipelinesTestRunId":"7703738","Reason":"Schedule","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","System.JobName":"__default","System.PhaseName":"run_test_p1__osx_x64_checked","Project":"public","BuildId":"364376","architecture":"x64","DefinitionId":"109","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseAttempt":"1","System.StageName":"Build","configuration":"Checked-jitstress1_tiered","operatingSystem":"OSX.1200.Amd64.Open","DefinitionName":"runtime-coreclr jitstress"} Schedule
2023-04-26T06:10:17.798Z runtime-coreclr jitstress Checked-jitstress2 osx.1200.amd64.open x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"BuildId":"252731","Reason":"Schedule","System.PhaseName":"run_test_p1__osx_x64_checked","System.PhaseAttempt":"1","DefinitionName":"runtime-coreclr jitstress","AzurePipelinesTestRunId":"4906790","Project":"public","operatingSystem":"OSX.1200.Amd64.Open","System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","configuration":"Checked-jitstress2","DefinitionId":"109","System.StageName":"Build","BuildNumber":"20230425.5","System.JobId":"bf644a0b-2dbe-5a03-d8c6-a86fdd97c823","architecture":"x64","System.JobName":"__default","System.JobAttempt":"1"} Schedule
2023-04-26T05:27:22.852Z runtime-coreclr jitstress Checked-jitstress2 ubuntu.1804.armarch.open arm64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"System.StageName":"Build","System.JobName":"__default","operatingSystem":"(Ubuntu.1804.Arm64.Open)[email protected]/dotnet-buildtools/prereqs:ubuntu-18.04-helix-arm64v8","configuration":"Checked-jitstress2","System.StageAttempt":"1","System.JobId":"34b2f53b-add1-5e74-7a39-5a11483297fc","Project":"public","BuildId":"252731","DefinitionName":"runtime-coreclr jitstress","architecture":"arm64","DefinitionId":"109","Reason":"Schedule","AzurePipelinesTestRunId":"4906414","System.PhaseName":"run_test_p1__linux_arm64_checked","CollectionUri":"https://dev.azure.com/dnceng-public/","System.JobAttempt":"1","BuildNumber":"20230425.5","System.PhaseAttempt":"1"} Schedule
2023-04-26T05:25:23.22Z runtime-coreclr jitstress Checked-jitstress2 ubuntu.1804.armarch.open arm JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"CollectionUri":"https://dev.azure.com/dnceng-public/","System.PhaseName":"run_test_p1__linux_arm_checked","operatingSystem":"(Ubuntu.1804.Arm32.Open)[email protected]/dotnet-buildtools/prereqs:ubuntu-18.04-helix-arm32v7","System.StageName":"Build","System.JobId":"860c965f-b28e-50d5-65d2-e40bd59f3a69","BuildNumber":"20230425.5","System.JobName":"__default","Reason":"Schedule","System.PhaseAttempt":"1","architecture":"arm","configuration":"Checked-jitstress2","Project":"public","DefinitionName":"runtime-coreclr jitstress","BuildId":"252731","DefinitionId":"109","AzurePipelinesTestRunId":"4906372","System.JobAttempt":"1","System.StageAttempt":"1"} Schedule
2023-04-26T05:25:21.005Z runtime-coreclr jitstress Checked-jitstress2_tiered ubuntu.1804.armarch.open arm JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"CollectionUri":"https://dev.azure.com/dnceng-public/","System.StageAttempt":"1","configuration":"Checked-jitstress2_tiered","DefinitionId":"109","BuildNumber":"20230425.5","System.PhaseAttempt":"1","BuildId":"252731","operatingSystem":"(Ubuntu.1804.Arm32.Open)[email protected]/dotnet-buildtools/prereqs:ubuntu-18.04-helix-arm32v7","Project":"public","AzurePipelinesTestRunId":"4906374","DefinitionName":"runtime-coreclr jitstress","System.JobAttempt":"1","System.JobName":"__default","System.PhaseName":"run_test_p1__linux_arm_checked","System.JobId":"860c965f-b28e-50d5-65d2-e40bd59f3a69","architecture":"arm","Reason":"Schedule","System.StageName":"Build"} Schedule
2023-04-26T05:25:12.735Z runtime-coreclr jitstress Checked-jitstress2 ubuntu.1804.amd64.open.rt x64 JIT/superpmi/superpmicollect/superpmicollect.sh Failed {"System.StageAttempt":"1","CollectionUri":"https://dev.azure.com/dnceng-public/","operatingSystem":"Ubuntu.1804.Amd64.Open","BuildId":"252731","System.JobAttempt":"1","Project":"public","DefinitionId":"109","System.JobId":"6dfec640-5b96-5d95-2a5b-7c236ea2d5c5","configuration":"Checked-jitstress2","System.JobName":"__default","Reason":"Schedule","DefinitionName":"runtime-coreclr jitstress","System.StageName":"Build","BuildNumber":"20230425.5","architecture":"x64","AzurePipelinesTestRunId":"4906396","System.PhaseAttempt":"1","System.PhaseName":"run_test_p1__linux_x64_checked"} Schedule
@v-wenyuxu v-wenyuxu added arch-x86 os-windows JitStress CLR JIT issues involving JIT internal stress modes labels Aug 17, 2023
@dotnet-issue-labeler dotnet-issue-labeler bot added the area-CodeGen-coreclr CLR JIT compiler in src/coreclr/src/jit and related components such as SuperPMI label Aug 17, 2023
@ghost ghost added the untriaged New issue has not been triaged by the area owner label Aug 17, 2023
@ghost
Copy link

ghost commented Aug 17, 2023

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

Issue Details

Failed in: runtime-coreclr jitstress 20230815.1

Failed tests:

coreclr windows x86 Checked jitstress2_tiered @ Windows.10.Amd64.Open
    - JIT\\superpmi\\superpmicollect\\superpmicollect.cmd

Error message:

minkernel\crts\ucrt\inc\corecrt_internal_stdio_output.h(1690) : Assertion failed: ("Incorrect format specifier", 0)
ERROR: Test C:\h\w\AC2A0925\w\ACDC09A0\e\JIT\superpmi\superpmicollect\Bytemark\Bytemark.cmd failed

Return code:      1
Raw output file:      C:\h\w\AC2A0925\w\ACDC09A0\uploads\Reports\JIT.superpmi\superpmicollect\superpmicollect.output.txt
Raw output:
BEGIN EXECUTION
 "C:\h\w\AC2A0925\p\corerun.exe" -p "System.Reflection.Metadata.MetadataUpdater.IsSupported=false" -p "System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true"  superpmicollect.dll 
SuperPMI collection and playback - BEGIN
Setting environment variables:
    SuperPMIShimLogPath=C:\h\w\AC2A0925\t\b5x0svar.zn5SPMI
    SuperPMIShimPath=C:\h\w\AC2A0925\p\clrjit.dll
    DOTNET_JitName=superpmi-shim-collector.dll
Running: C:\Windows\system32\cmd.exe /c C:\h\w\AC2A0925\w\ACDC09A0\e\JIT\superpmi\superpmicollect\Bytemark\Bytemark.cmd
BEGIN EXECUTION
 "C:\h\w\AC2A0925\p\corerun.exe" -p "System.Reflection.Metadata.MetadataUpdater.IsSupported=false" -p "System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true"  Bytemark.dll 
BBBBBB   YYY   Y  TTTTTTT  EEEEEEE
BBB   B  YYY   Y    TTT    EEE
BBB   B  YYY   Y    TTT    EEE
BBBBBB    YYY Y     TTT    EEEEEEE
BBB   B    YYY      TTT    EEE
BBB   B    YYY      TTT    EEE
BBBBBB     YYY      TTT    EEEEEEE

BYTEmark (tm) C# Mode Benchmark ver. 2 (06/99)
NUMERIC SORT(jagged):  Iterations/sec: 984.53581  Index: 25.24904
NUMERIC SORT(rectangle):  Iterations/sec: 674.65136  Index: 17.30186
STRING SORT:  Iterations/sec: 5259.85300  Index: 2350.24710
BITFIELD:  Iterations/sec: 249331402.35652  Index: 42.76914
FP EMULATION(struct):  Iterations/sec: 126.60000  Index: 60.74856
FP EMULATION(class):  Iterations/sec: 129.60000  Index: 62.18810
FOURIER:  Iterations/sec: 11123.96726  Index: 12.65125
ASSIGNMENT(jagged):Expected: 100
Actual: -1073740791
END EXECUTION - FAILED
FAILED
SuperPMI collection and playback - FAILED
Expected: 100
Actual: 101
END EXECUTION - FAILED
FAILED
Test failed. Trying to see if dump file was created in C:\cores since 8/16/2023 5:53:46 AM
Processing C:\cores\corerun.exe.4552.dmp
Invoking: C:\Program Files (x86)\Windows Kits\10\Debuggers\x86\cdb.exe -c "$<C:\h\w\AC2A0925\t\tmphit0yx.tmp" -z "C:\cores\corerun.exe.4552.dmp"
stdout: 
Microsoft (R) Windows Debugger Version 10.0.18362.1 X86
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [C:\cores\corerun.exe.4552.dmp]
User Mini Dump File with Full Memory: Only application data is available


************* Path validation summary **************
Response                         Time (ms)     Location
OK                                             C:\h\w\AC2A0925\p\PDB
Symbol search path is: C:\h\w\AC2A0925\p\PDB
Executable search path is: 
Windows 10 Version 14393 MP (4 procs) Free x86 compatible
Product: Server, suite: TerminalServer DataCenter SingleUserTS
10.0.14393.5125 (rs1_release.220429-1732)
Machine Name:
Debug session time: Wed Aug 16 05:54:54.000 2023 (UTC + 0:00)
System Uptime: 0 days 0:05:20.414
Process Uptime: 0 days 0:01:05.000
.................................

************* Symbol Loading Error Summary **************
Module name            Error
ntdll                  The system cannot find the file specified

You can troubleshoot most symbol related issues by turning on symbol loading diagnostics (!sym noisy) and repeating the command that caused symbols to be loaded.
You should also verify that your symbol search path (.sympath) is correct.
This dump file has an exception of interest stored in it.
The stored exception information can be accessed via .ecxr.
(11c8.dc4): Security check failure or stack buffer overrun - code c0000409 (first/second chance not available)
For analysis of this file, run !analyze -v
*** WARNING: Unable to verify checksum for superpmi-shim-collector.dll
eax=00000001 ebx=04a26260

Stack trace:

   at JIT_superpmi._superpmicollect_superpmicollect_._superpmicollect_superpmicollect_cmd()
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(Object obj, IntPtr* args)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
Author: v-wenyuxu
Assignees: -
Labels:

arch-x86, os-windows, JitStress, area-CodeGen-coreclr

Milestone: -

@BruceForstall BruceForstall self-assigned this Aug 17, 2023
@BruceForstall BruceForstall added this to the 8.0.0 milestone Aug 17, 2023
@ghost ghost removed the untriaged New issue has not been triaged by the area owner label Aug 17, 2023
@BruceForstall
Copy link
Member

Latest jitstress run has none of these failures:

https://dev.azure.com/dnceng-public/public/_build/results?buildId=377027&view=ms.vss-test-web.build-test-results-tab

(However, filtering on 'superpmicollect' only shows that it ran on linux, which is worrisome. Maybe just a bug in reporting/AzDO, and it actually did run?)

@BruceForstall
Copy link
Member

@BruceForstall
Copy link
Member

Looking at a win-x86 dump, it looks like a problem with the SuperPMI macro-ized assertion helper.

The JIT is calling getHelperFtn() with CORINFO_HELP_CHKCASTCLASS_SPECIAL and is hitting this assert:

AssertCodeMsg(oldValue.A == value.A && oldValue.B == oldValue.B, EXCEPTIONCODE_MC,
"collision! old: %016" PRIX64 " %016" PRIX64 ", new: %016" PRIX64 " %016" PRIX64 " \n", oldValue.A, oldValue.B, value.A,
value.B);

This indicates that the VM has returned two different values for the same helper number.

In particular, the VM changes from indirect to direct address.

It looks like this recently changed with #90412. @EgorBo PTAL -- there is probably a superpmi issue with your change, if the value returned by this function changes over time.

However, there is a superpmi issue here because the formatting string gets macro string-ized before the "PRIX64" are replaced, so superpmi needs to handle this so we get an actual assert, and not a failure in the CRT of "Incorrect format specifier".

@BruceForstall
Copy link
Member

#90778 fixes the problem with this AssertCodeMsg.

The remaining problem is the underlying problem of this API returning different results given the same CorInfoHelpFunc in multiple different calls. SuperPMI can't handle that.

Assigning this to @EgorBo

@BruceForstall BruceForstall added blocking-outerloop Blocking the 'runtime-coreclr outerloop' and 'runtime-libraries-coreclr outerloop' runs and removed arch-x86 os-windows JitStress CLR JIT issues involving JIT internal stress modes labels Aug 18, 2023
@BruceForstall
Copy link
Member

cc @dotnet/jit-contrib -- there's a new problem where SuperPMI collection is failing because the JIT is calling getHelperFtn() multiple times and getting back different results.

@EgorBo
Copy link
Member

EgorBo commented Aug 18, 2023

Thanks for finding the cause! it seems that it's indeed possible. Since it happens in lower (LowerCall) presumably for jit itself it should not cause any problems that the same helper was first emitted as indirect and then later as direct (cc @jkotas) in some other block (but not in the opposite order).

Should we special-case this in SPMI or better to introduce a jit-level cache for addresses to make sure it uses the same address per compilation (potentially might decrease perf for a case where previosly we could emit a direct call)?

@BruceForstall
Copy link
Member

Should we special-case this in SPMI or better to introduce a jit-level cache for addresses to make sure it uses the same address per compilation (potentially might decrease perf for a case where previosly we could emit a direct call)?

So the JIT could possibly generate one call as indirect and a subsequent call as direct simply based on timing of when the two calls from the JIT are made? That would make any codegen issues really hard to debug as we couldn't guarantee repeatable codegen. I would argue the JIT should pick one and use it everywhere (even if that makes the code slightly less optimal). That presumably means the JIT should only call getHelperFtn once per helper function number (and cache the result).

@jkotas
Copy link
Member

jkotas commented Aug 18, 2023

This problem is not limited to getHelperFtn. There are number of other flags and pointers on JIT/EE interface that will change their results over time if there is activity on other threads. It would be expensive to cache all these.

For system as a whole, we have been going further and further away from guaranteeing repeatable codegen with tiering and dynamic PGO.

@jkotas
Copy link
Member

jkotas commented Aug 18, 2023

for jit itself it should not cause any problems that the same helper was first emitted as indirect and then later as direct

Yes, I do not see a problem with it.

You can get into same situation with constructor triggers or with direct/indirect method calls.

@BruceForstall
Copy link
Member

It seems generally worrisome for the JIT to make decisions based on the results of calling a JIT-EE API and then call that API again and have the results change, leading to different decisions. It seems dangerous if those decisions need to be coherent.

In fact, why does the JIT need to call the API multiple times? Why isn't the result incorporated into the IR (e.g., ABI information)?

SuperPMI only stores one value for a given set of input arguments. This happens to be a case where someone added an assert that the value doesn't change. If we allow the values to change, you can just remove the assert. SuperPMI replay will then not generate the same codegen as the recording since it will only use the latest value. This makes SuperPMI less useful as a repro tool for failures, etc. (which is currently only an aspirational goal, not actual behavior).

There are various cases where it seems like the JIT should cache the results of JIT/EE interface calls to avoid re-calling on the same arguments over and over again, especially for things that might be expensive (e.g., possibly SysV ABI info).

@EgorBo
Copy link
Member

EgorBo commented Aug 18, 2023

Why isn't the result incorporated into the IR (e.g., ABI information)?

The repro case is two different calls with the same helperId, it's not that JIT calls that API for the same GenTreeCall instance twice now. I share your concerns that it makes it potentiall error-prone. Unfortunately, just like Jan pointed out, we have other places with similiar behavior so we can't afford the "all EE functions are pure" thinking anyway, e.g. an API that checks whether a class is initialized or not yet (it might become initialized between two calls from the current jit compilation).

Let me quickly prototypr a jit-level cache for addresses to see how it'd look like

@EgorBo
Copy link
Member

EgorBo commented Aug 18, 2023

Why does SPMI have that assert in getHelperFtn in the first place while other functions like getClassAttribs don't have it?

if (GetHelperFtn->GetIndex(key) != -1)
{
DLDL oldValue = GetHelperFtn->Get(key);
AssertCodeMsg(oldValue.A == value.A && oldValue.B == oldValue.B, EXCEPTIONCODE_MC,
"collision! old: %016" PRIX64 " %016" PRIX64 ", new: %016" PRIX64 " %016" PRIX64 " \n", oldValue.A, oldValue.B, value.A,
value.B);
}

getClassAttribs:

if (GetClassAttribs == nullptr)
GetClassAttribs = new LightWeightMap<DWORDLONG, DWORD>();
DWORDLONG key = CastHandle(classHandle);
GetClassAttribs->Add(key, attribs);
DEBUG_REC(dmpGetClassAttribs(key, attribs));

@BruceForstall
Copy link
Member

Why does SPMI have that assert in getHelperFtn in the first place while other functions like getClassAttribs don't have it?

I don't know. You can try looking through history, but it's likely to have been this way for a while. My guess would be that it was considered a problem at some point.

The more I think about it, the more it worries me that JIT-EE calls can change what they return during the time of a single function compilation. I understand that the VM state might change due to threading, etc., but that makes me think the JIT should be caching data that might change between calls.

In general, it seems like the JIT shouldn't be asking for the same data over and over again anyway; that seems potentially like the JIT is just being lazy and NOT caching (e.g., storing in result in IR).

It looks like SPMI actually ignores any attempt to overwrite a value that's already been added:

int resItem = memcmp(&pItems[mid], &item, sizeof(_Item));
if (resItem != 0)
{
LogDebug("Tried to add a new value for an existing key, the new value was ignored");
}
return false; // found it. return position /////

However, it uses LogDebug instead of an Assert so it probably gets silently ignored, especially during collections. If we turn these into Asserts we can find out how widespread the problem is.

@EgorBo
Copy link
Member

EgorBo commented Aug 18, 2023

The more I think about it, the more it worries me that JIT-EE calls can change what they return during the time of a single function compilation.

Maybe we should audit the list of JIT-EE functions and mark the ones which can change the value as NonInvariant so SPMI could be more strict for the ones which are invariant. I think we can't make a general cache for JIT-EE values, e.g. we're jitting

void Foo()
{
    Bar();
    Bar();
}

We try to inline Bar() and realize it's not profitable (or legal) to inline it - VM marks it as noinlining, so when we try to inline the 2nd call of Bar, getMethodAttribs will get us a different set of attributes for the same method handle - it will append NOINLINE to it.

@BruceForstall
Copy link
Member

Maybe we should audit the list of JIT-EE functions and mark the ones which can change the value as NonInvariant so SPMI could be more strict for the ones which are invariant.

That would be a good start.

What does SPMI do in your example case today? Presumably it stores the first result during collection, so during playback the JIT gets the first result for both calls, and resulting codegen is the same as original codegen -- the NOINLINE bit is simply an optimization? (I.e., if the JIT decided it wasn't profitable/legal the first time, it presumably will make the same determination the second time)

@jkotas
Copy link
Member

jkotas commented Aug 18, 2023

Also, consider refactoring the JIT/EE interface to split the variant and invariant info. For example, most getMethodAttribs are invariant, but there are a few that are variant that would be better to separate.

@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Aug 21, 2023
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Aug 22, 2023
@ghost ghost locked as resolved and limited conversation to collaborators Sep 21, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-CodeGen-coreclr CLR JIT compiler in src/coreclr/src/jit and related components such as SuperPMI blocking-outerloop Blocking the 'runtime-coreclr outerloop' and 'runtime-libraries-coreclr outerloop' runs
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants