superpmi-diffs failures/timeouts

[jakobbotsch]

There are quite a few failures in superpmi-diffs:
https://dev.azure.com/dnceng-public/public/_build/results?buildId=38383&view=results

They look related to my recent changes:

[05:53:33] Total instructions executed by base: 228005614998

[05:53:33] Total instructions executed by diff: 228005774156

[05:53:33] Total instructions executed delta: 159158 (0.00% of base)

[05:53:33] Running throughput diff of C:\h\w\C7D40AC4\p\artifacts\spmi\mch\eb8352bd-0a13-4b5b-badb-58f9ecc40c44.Linux.x64\libraries_tests.pmi.Linux.x64.checked.mch

[05:53:33] Invoking: C:\h\w\C7D40AC4\p\artifacts\spmi\pintools\1.0\windows\pin.exe -follow_execv -t C:\h\w\C7D40AC4\p\artifacts\spmi\pintools\1.0\windows\clrjit_inscount_x64\clrjit_inscount.dll -quiet -- C:\h\w\C7D40AC4\p\superpmi.exe -applyDiff -baseMetricsSummary C:\h\w\C7D40AC4\t\tmpitoan9nv\libraries_tests.pmi.Linux.x64.checked.mch_base_metrics.csv -diffMetricsSummary C:\h\w\C7D40AC4\t\tmpitoan9nv\libraries_tests.pmi.Linux.x64.checked.mch_diff_metrics.csv -p -failureLimit 100 C:\h\w\C7D40AC4\p\base\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\diff\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\artifacts\spmi\mch\eb8352bd-0a13-4b5b-badb-58f9ecc40c44.Linux.x64\libraries_tests.pmi.Linux.x64.checked.mch

[05:59:20] Using child (C:\h\w\C7D40AC4\p\superpmi.exe) with args ( -applyDiff C:\h\w\C7D40AC4\p\base\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\diff\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\artifacts\spmi\mch\eb8352bd-0a13-4b5b-badb-58f9ecc40c44.Linux.x64\libraries_tests.pmi.Linux.x64.checked.mch)

[05:59:20]  workerCount=4, skipCleanup=0.

[05:59:20] Loaded 330299  Jitted 330299  FailedCompile 0 Excluded 0 Missing 0 Diffs 0

[05:59:20] Total time: 345701.861700ms

[05:59:20] return_code: 0

[05:59:20] Total instructions executed by base: 465984195367

[05:59:20] Total instructions executed by diff: 465984616757

[05:59:20] Total instructions executed delta: 421390 (0.00% of base)

[05:59:20] Throughput diff summary:


Traceback (most recent call last):

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 4371, in <module>

    sys.exit(main(args))

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 4293, in main

    success = tp_diff.replay_with_throughput_diff()

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2249, in replay_with_throughput_diff

    if any(is_significant(row, base, diff) for row in ["Overall", "MinOpts", "FullOpts"] for (_, base, diff) in tp_diffs):

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2249, in <genexpr>

    if any(is_significant(row, base, diff) for row in ["Overall", "MinOpts", "FullOpts"] for (_, base, diff) in tp_diffs):

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2239, in is_significant

    return is_significant_pct(int(base[row]["Diff executed instructions"]), int(diff[row]["Diff executed instructions"]))

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2237, in is_significant_pct

    return round((diff - base) / base * 100, 2) != 0

ZeroDivisionError: division by zero

I think I only added correct handling for asmdiffs here and forgot it for tpdiff.

[ghost]

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

Issue Details

---

There are quite a few failures in superpmi-diffs:
https://dev.azure.com/dnceng-public/public/_build/results?buildId=38383&view=results

They look related to my recent changes:

[05:53:33] Total instructions executed by base: 228005614998

[05:53:33] Total instructions executed by diff: 228005774156

[05:53:33] Total instructions executed delta: 159158 (0.00% of base)

[05:53:33] Running throughput diff of C:\h\w\C7D40AC4\p\artifacts\spmi\mch\eb8352bd-0a13-4b5b-badb-58f9ecc40c44.Linux.x64\libraries_tests.pmi.Linux.x64.checked.mch

[05:53:33] Invoking: C:\h\w\C7D40AC4\p\artifacts\spmi\pintools\1.0\windows\pin.exe -follow_execv -t C:\h\w\C7D40AC4\p\artifacts\spmi\pintools\1.0\windows\clrjit_inscount_x64\clrjit_inscount.dll -quiet -- C:\h\w\C7D40AC4\p\superpmi.exe -applyDiff -baseMetricsSummary C:\h\w\C7D40AC4\t\tmpitoan9nv\libraries_tests.pmi.Linux.x64.checked.mch_base_metrics.csv -diffMetricsSummary C:\h\w\C7D40AC4\t\tmpitoan9nv\libraries_tests.pmi.Linux.x64.checked.mch_diff_metrics.csv -p -failureLimit 100 C:\h\w\C7D40AC4\p\base\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\diff\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\artifacts\spmi\mch\eb8352bd-0a13-4b5b-badb-58f9ecc40c44.Linux.x64\libraries_tests.pmi.Linux.x64.checked.mch

[05:59:20] Using child (C:\h\w\C7D40AC4\p\superpmi.exe) with args ( -applyDiff C:\h\w\C7D40AC4\p\base\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\diff\release\clrjit_unix_x64_x64.dll C:\h\w\C7D40AC4\p\artifacts\spmi\mch\eb8352bd-0a13-4b5b-badb-58f9ecc40c44.Linux.x64\libraries_tests.pmi.Linux.x64.checked.mch)

[05:59:20]  workerCount=4, skipCleanup=0.

[05:59:20] Loaded 330299  Jitted 330299  FailedCompile 0 Excluded 0 Missing 0 Diffs 0

[05:59:20] Total time: 345701.861700ms

[05:59:20] return_code: 0

[05:59:20] Total instructions executed by base: 465984195367

[05:59:20] Total instructions executed by diff: 465984616757

[05:59:20] Total instructions executed delta: 421390 (0.00% of base)

[05:59:20] Throughput diff summary:


Traceback (most recent call last):

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 4371, in <module>

    sys.exit(main(args))

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 4293, in main

    success = tp_diff.replay_with_throughput_diff()

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2249, in replay_with_throughput_diff

    if any(is_significant(row, base, diff) for row in ["Overall", "MinOpts", "FullOpts"] for (_, base, diff) in tp_diffs):

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2249, in <genexpr>

    if any(is_significant(row, base, diff) for row in ["Overall", "MinOpts", "FullOpts"] for (_, base, diff) in tp_diffs):

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2239, in is_significant

    return is_significant_pct(int(base[row]["Diff executed instructions"]), int(diff[row]["Diff executed instructions"]))

  File "C:\h\w\C7D40AC4\p\superpmi.py", line 2237, in is_significant_pct

    return round((diff - base) / base * 100, 2) != 0

ZeroDivisionError: division by zero

I think I only added correct handling for asmdiffs here and forgot it for tpdiff.

Author:	jakobbotsch
Assignees:	-
Labels:	area-CodeGen-coreclr
Milestone:	-

[jakobbotsch]

This change is some weeks old at this point though, it is odd we only hit it now, I wonder if something else also changed.

[jakobbotsch]

Current libraries.crossgen2 collection has 0 minopts contexts which is why we hit the problem. I'm not sure why there were any minopts contexts before, seems odd.