Skip to content
This repository was archived by the owner on Jan 23, 2023. It is now read-only.

Improve Windows test build performance by building projects in groups - 4x less memory 326% faster build. #17161

Merged
merged 1 commit into from
Mar 28, 2018

Conversation

4creators
Copy link

@4creators 4creators commented Mar 23, 2018

Fixes #14594 and is a part of #17149

The build time improvement for priority 1 tests: 02:09:09.700 (2 hours 9 minutes 9 seconds .700) on 03:46:42.325 original time and now takes 01:37:32.619 what means that build and test is ~132% faster.

Test build time improved from 02:45:09:518 to 00:38:47.199 what is ~326% faster.

@4creators
Copy link
Author

test Windows_NT x64 Checked jitincompletehwintrinsic
test Windows_NT x64 Checked jitx86hwintrinsicnoavx2
test Windows_NT x64 Checked jitx86hwintrinsicnosimd

test Windows_NT x86 Checked jitincompletehwintrinsic
test Windows_NT x86 Checked jitx86hwintrinsicnoavx2
test Windows_NT x86 Checked jitx86hwintrinsicnosimd

test Ubuntu x64 Checked jitincompletehwintrinsic
test Ubuntu x64 Checked jitx86hwintrinsicnoavx2
test Ubuntu x64 Checked jitx86hwintrinsicnosimd

@4creators
Copy link
Author

Performance comparison between priority 1 build and test runs - time elapsed from build start is on the left:

With MSBuild cache workaround:
https://ci.dot.net/job/dotnet_coreclr/job/master/job/jitstress/job/x64_checked_windows_nt_jitincompletehwintrinsic_prtest/231/

00:15:46.973 BUILDTEST: Commencing CoreCLR repo test build
00:15:46.976 BUILDTEST: Checking prerequisites
00:54:34.172 BUILDTEST: Test build successful.
00:54:34.172 BUILDTEST: Test binaries are available at D:\j\workspace\x64_checked_w---1cba8152\bin\tests\Windows_NT.x64.Checked
01:37:31.510   === TEST EXECUTION SUMMARY ===
01:37:31.517      baseservices.compilerservices.XUnitWrapper       Total:    10, Errors: 0, Failed: 0, Skipped: 0, Time:    12.419s
01:37:31.517      baseservices.exceptions.XUnitWrapper             Total:   139, Errors: 0, Failed: 0, Skipped: 0, Time:   547.453s
01:37:31.517      baseservices.multidimmarray.XUnitWrapper         Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     7.898s
01:37:31.517      baseservices.regression.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     6.425s
01:37:31.517      baseservices.threading.XUnitWrapper              Total:   433, Errors: 0, Failed: 0, Skipped: 0, Time:  2106.365s
01:37:31.517      baseservices.varargs.XUnitWrapper                Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:     6.255s
01:37:31.517      CoreMangLib.components.XUnitWrapper              Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:     5.843s
01:37:31.517      CoreMangLib.cti.XUnitWrapper                     Total:  2055, Errors: 0, Failed: 0, Skipped: 0, Time:  2506.745s
01:37:31.517      CoreMangLib.system.XUnitWrapper                  Total:    16, Errors: 0, Failed: 0, Skipped: 0, Time:    77.553s
01:37:31.517      Exceptions.Finalization.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     6.111s
01:37:31.517      Exceptions.ForeignThread.XUnitWrapper            Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     6.342s
01:37:31.517      GC.API.XUnitWrapper                              Total:    71, Errors: 0, Failed: 0, Skipped: 0, Time:   366.584s
01:37:31.517      GC.Coverage.XUnitWrapper                         Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    28.225s
01:37:31.517      GC.Features.XUnitWrapper                         Total:    41, Errors: 0, Failed: 0, Skipped: 0, Time:   224.396s
01:37:31.517      GC.LargeMemory.XUnitWrapper                      Total:     6, Errors: 0, Failed: 0, Skipped: 0, Time:    19.568s
01:37:31.517      GC.Regressions.XUnitWrapper                      Total:    11, Errors: 0, Failed: 0, Skipped: 0, Time:    45.906s
01:37:31.517      GC.Scenarios.XUnitWrapper                        Total:   479, Errors: 0, Failed: 0, Skipped: 0, Time:  1006.173s
01:37:31.517      Interop.ArrayMarshalling.XUnitWrapper            Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:    33.890s
01:37:31.517      Interop.BestFitMapping.XUnitWrapper              Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    13.124s
01:37:31.517      Interop.FuncPtrAsDelegateParam.XUnitWrapper      Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    14.027s
01:37:31.517      Interop.ICastable.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    12.461s
01:37:31.517      Interop.MarshalAPI.XUnitWrapper                  Total:    26, Errors: 0, Failed: 0, Skipped: 0, Time:    55.151s
01:37:31.517      Interop.NativeCallable.XUnitWrapper              Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    11.106s
01:37:31.517      Interop.PrimitiveMarshalling.XUnitWrapper        Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    11.373s
01:37:31.517      Interop.RefCharArray.XUnitWrapper                Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     4.707s
01:37:31.517      Interop.RefInt.XUnitWrapper                      Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    13.005s
01:37:31.517      Interop.SimpleStruct.XUnitWrapper                Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     8.005s
01:37:31.517      Interop.SizeConst.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     6.418s
01:37:31.517      Interop.StringMarshalling.XUnitWrapper           Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:     6.178s
01:37:31.517      Interop.StructMarshalling.XUnitWrapper           Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:    21.847s
01:37:31.517      Interop.StructPacking.XUnitWrapper               Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    16.254s
01:37:31.517      JIT.BBT.XUnitWrapper                             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    10.066s
01:37:31.517      JIT.CheckProjects.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    30.279s
01:37:31.517      JIT.CodeGenBringUpTests.XUnitWrapper             Total:   159, Errors: 0, Failed: 0, Skipped: 0, Time:   582.949s
01:37:31.517      JIT.Directed.XUnitWrapper                        Total:   607, Errors: 0, Failed: 0, Skipped: 0, Time:  1338.978s
01:37:31.517      JIT.Generics.XUnitWrapper                        Total:   219, Errors: 0, Failed: 0, Skipped: 0, Time:   740.878s
01:37:31.517      JIT.HardwareIntrinsics.XUnitWrapper              Total:   355, Errors: 0, Failed: 0, Skipped: 0, Time:   948.049s
01:37:31.517      JIT.IL_Conformance.XUnitWrapper                  Total:   404, Errors: 0, Failed: 0, Skipped: 0, Time:   938.332s
01:37:31.517      JIT.Intrinsics.XUnitWrapper                      Total:    12, Errors: 0, Failed: 0, Skipped: 0, Time:    79.735s
01:37:31.517      JIT.jit64.XUnitWrapper                           Total:   865, Errors: 0, Failed: 0, Skipped: 0, Time:  1726.639s
01:37:31.518      JIT.Methodical.XUnitWrapper                      Total:  2075, Errors: 0, Failed: 0, Skipped: 0, Time:  2425.437s
01:37:31.518      JIT.opt.XUnitWrapper                             Total:   137, Errors: 0, Failed: 0, Skipped: 0, Time:   471.389s
01:37:31.518      JIT.Performance.XUnitWrapper                     Total:    83, Errors: 0, Failed: 0, Skipped: 0, Time:   434.781s
01:37:31.518      JIT.Regression.XUnitWrapper                      Total:  1275, Errors: 0, Failed: 0, Skipped: 0, Time:  1802.919s
01:37:31.518      JIT.RyuJIT.XUnitWrapper                          Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     5.931s
01:37:31.518      JIT.SIMD.XUnitWrapper                            Total:   108, Errors: 0, Failed: 0, Skipped: 0, Time:   424.571s
01:37:31.518      JIT.superpmi.XUnitWrapper                        Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:   235.119s
01:37:31.518      Loader.binding.XUnitWrapper                      Total:     7, Errors: 0, Failed: 0, Skipped: 0, Time:   234.411s
01:37:31.518      Loader.classloader.XUnitWrapper                  Total:  1973, Errors: 0, Failed: 0, Skipped: 0, Time:  2388.132s
01:37:31.518      Loader.lowlevel.XUnitWrapper                     Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    32.062s
01:37:31.518      Loader.multimodule.XUnitWrapper                  Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    28.480s
01:37:31.518      Loader.NativeLibs.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     7.888s
01:37:31.518      Loader.regressions.XUnitWrapper                  Total:     4, Errors: 0, Failed: 0, Skipped: 0, Time:    39.815s
01:37:31.518      Loader.versioning.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    17.893s
01:37:31.518      managed.Compilation.XUnitWrapper                 Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    51.448s
01:37:31.518      readytorun.tests.XUnitWrapper                    Total:     6, Errors: 0, Failed: 0, Skipped: 0, Time:    39.477s
01:37:31.518      reflection.DefaultInterfaceMethods.XUnitWrapper  Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    30.021s
01:37:31.518      reflection.ldtoken.XUnitWrapper                  Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:    35.206s
01:37:31.518      reflection.regression.XUnitWrapper               Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:    29.719s
01:37:31.518      reflection.Tier1Collectible.XUnitWrapper         Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    25.760s
01:37:31.518      Regressions.assemblyref.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     7.443s
01:37:31.518      Regressions.common.XUnitWrapper                  Total:    15, Errors: 0, Failed: 0, Skipped: 0, Time:    83.409s
01:37:31.518      Regressions.coreclr.XUnitWrapper                 Total:    53, Errors: 0, Failed: 0, Skipped: 0, Time:   347.476s
01:37:31.518      Regressions.expl_double.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    10.362s
01:37:31.518      tracing.eventactivityidcontrol.XUnitWrapper      Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    10.253s
01:37:31.518      tracing.eventlistener.XUnitWrapper               Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    10.980s
01:37:31.518      tracing.eventsourcetrace.XUnitWrapper.dll        Total:     0
01:37:31.518      tracing.tracevalidation.XUnitWrapper             Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    28.782s
01:37:31.518                                                              -----          -          -           -        ----------
01:37:31.519                                                 GRAND TOTAL: 11698          0          0           0        22862.879s (2553.701s)
01:37:32.619 
01:37:32.619 Build succeeded.
01:37:32.619     0 Warning(s)
01:37:32.619     0 Error(s)
01:37:32.619 
01:37:32.619 Time Elapsed 00:42:36.95
01:37:32.625 RUNTEST: Test run successful. Refer to the log files for details:
01:37:32.625     D:\j\workspace\x64_checked_w---1cba8152\tests\..\bin\Logs\TestRun_Windows_NT__x64__Checked.html
01:37:32.625     D:\j\workspace\x64_checked_w---1cba8152\tests\..\bin\Logs\TestRun_Windows_NT__x64__Checked.xml
01:37:32.976 [x64_checked_w---1cba8152] $ cmd /c call C:\Users\DOTNET~1\AppData\Local\Temp\jenkins6498336450786809472.bat
01:37:32.988 
01:37:32.988 D:\j\workspace\x64_checked_w---1cba8152>build.cmd checked x64 linuxmscorlib 

Without MSBuild cache workaround:
https://ci.dot.net/job/dotnet_coreclr/job/master/job/jitstress/job/x64_checked_windows_nt_jitincompletehwintrinsic_prtest/230/

00:16:12.482 BUILDTEST: Commencing CoreCLR repo test build
00:16:12.485 BUILDTEST: Checking prerequisites
03:01:22.000 BUILDTEST: Test build successful.
03:01:22.000 BUILDTEST: Test binaries are available at D:\j\workspace\x64_checked_w---1cba8152\bin\tests\Windows_NT.x64.Checked
03:46:41.118   === TEST EXECUTION SUMMARY ===
03:46:41.123      baseservices.compilerservices.XUnitWrapper       Total:    10, Errors: 0, Failed: 0, Skipped: 0, Time:    14.889s
03:46:41.123      baseservices.exceptions.XUnitWrapper             Total:   139, Errors: 0, Failed: 0, Skipped: 0, Time:   556.110s
03:46:41.123      baseservices.multidimmarray.XUnitWrapper         Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     8.387s
03:46:41.124      baseservices.regression.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     8.351s
03:46:41.124      baseservices.threading.XUnitWrapper              Total:   433, Errors: 0, Failed: 0, Skipped: 0, Time:  2186.194s
03:46:41.124      baseservices.varargs.XUnitWrapper                Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:     6.183s
03:46:41.124      CoreMangLib.components.XUnitWrapper              Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:     4.909s
03:46:41.127      CoreMangLib.cti.XUnitWrapper                     Total:  2055, Errors: 0, Failed: 0, Skipped: 0, Time:  2564.404s
03:46:41.127      CoreMangLib.system.XUnitWrapper                  Total:    16, Errors: 0, Failed: 0, Skipped: 0, Time:    69.250s
03:46:41.127      Exceptions.Finalization.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     4.864s
03:46:41.127      Exceptions.ForeignThread.XUnitWrapper            Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     9.009s
03:46:41.127      GC.API.XUnitWrapper                              Total:    71, Errors: 0, Failed: 0, Skipped: 0, Time:   372.295s
03:46:41.127      GC.Coverage.XUnitWrapper                         Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    18.237s
03:46:41.127      GC.Features.XUnitWrapper                         Total:    41, Errors: 0, Failed: 0, Skipped: 0, Time:   247.814s
03:46:41.128      GC.LargeMemory.XUnitWrapper                      Total:     6, Errors: 0, Failed: 0, Skipped: 0, Time:    37.409s
03:46:41.128      GC.Regressions.XUnitWrapper                      Total:    11, Errors: 0, Failed: 0, Skipped: 0, Time:    37.986s
03:46:41.128      GC.Scenarios.XUnitWrapper                        Total:   479, Errors: 0, Failed: 0, Skipped: 0, Time:  1093.970s
03:46:41.128      hosting.stress.XUnitWrapper                      Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    24.110s
03:46:41.128      Interop.ArrayMarshalling.XUnitWrapper            Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:    23.882s
03:46:41.129      Interop.BestFitMapping.XUnitWrapper              Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    19.751s
03:46:41.129      Interop.FuncPtrAsDelegateParam.XUnitWrapper      Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    20.609s
03:46:41.129      Interop.ICastable.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    20.610s
03:46:41.129      Interop.MarshalAPI.XUnitWrapper                  Total:    26, Errors: 0, Failed: 0, Skipped: 0, Time:    56.441s
03:46:41.130      Interop.NativeCallable.XUnitWrapper              Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     5.806s
03:46:41.130      Interop.PrimitiveMarshalling.XUnitWrapper        Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    11.155s
03:46:41.130      Interop.RefCharArray.XUnitWrapper                Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     9.375s
03:46:41.130      Interop.RefInt.XUnitWrapper                      Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     8.557s
03:46:41.130      Interop.SimpleStruct.XUnitWrapper                Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     8.115s
03:46:41.130      Interop.SizeConst.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     8.139s
03:46:41.130      Interop.StringMarshalling.XUnitWrapper           Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:     9.115s
03:46:41.130      Interop.StructMarshalling.XUnitWrapper           Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:     9.275s
03:46:41.130      Interop.StructPacking.XUnitWrapper               Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     6.358s
03:46:41.130      JIT.BBT.XUnitWrapper                             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     5.285s
03:46:41.130      JIT.CheckProjects.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    61.803s
03:46:41.130      JIT.CodeGenBringUpTests.XUnitWrapper             Total:   159, Errors: 0, Failed: 0, Skipped: 0, Time:   590.790s
03:46:41.130      JIT.Directed.XUnitWrapper                        Total:   607, Errors: 0, Failed: 0, Skipped: 0, Time:  1380.334s
03:46:41.130      JIT.Generics.XUnitWrapper                        Total:   219, Errors: 0, Failed: 0, Skipped: 0, Time:   789.397s
03:46:41.130      JIT.HardwareIntrinsics.XUnitWrapper              Total:   355, Errors: 0, Failed: 0, Skipped: 0, Time:   962.908s
03:46:41.130      JIT.IL_Conformance.XUnitWrapper                  Total:   404, Errors: 0, Failed: 0, Skipped: 0, Time:  1009.794s
03:46:41.130      JIT.Intrinsics.XUnitWrapper                      Total:    12, Errors: 0, Failed: 0, Skipped: 0, Time:   111.961s
03:46:41.130      JIT.jit64.XUnitWrapper                           Total:   865, Errors: 0, Failed: 0, Skipped: 0, Time:  1643.230s
03:46:41.130      JIT.Methodical.XUnitWrapper                      Total:  2075, Errors: 0, Failed: 0, Skipped: 0, Time:  2498.825s
03:46:41.131      JIT.opt.XUnitWrapper                             Total:   137, Errors: 0, Failed: 0, Skipped: 0, Time:   608.545s
03:46:41.131      JIT.Performance.XUnitWrapper                     Total:    83, Errors: 0, Failed: 0, Skipped: 0, Time:   446.113s
03:46:41.131      JIT.Regression.XUnitWrapper                      Total:  1275, Errors: 0, Failed: 0, Skipped: 0, Time:  2067.152s
03:46:41.131      JIT.RyuJIT.XUnitWrapper                          Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    21.914s
03:46:41.131      JIT.SIMD.XUnitWrapper                            Total:   108, Errors: 0, Failed: 0, Skipped: 0, Time:   413.576s
03:46:41.131      JIT.superpmi.XUnitWrapper                        Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:   244.082s
03:46:41.131      Loader.binding.XUnitWrapper                      Total:     7, Errors: 0, Failed: 0, Skipped: 0, Time:    47.518s
03:46:41.131      Loader.classloader.XUnitWrapper                  Total:  1973, Errors: 0, Failed: 0, Skipped: 0, Time:  2521.864s
03:46:41.131      Loader.lowlevel.XUnitWrapper                     Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    32.582s
03:46:41.131      Loader.multimodule.XUnitWrapper                  Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    24.523s
03:46:41.131      Loader.NativeLibs.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    25.955s
03:46:41.131      Loader.regressions.XUnitWrapper                  Total:     4, Errors: 0, Failed: 0, Skipped: 0, Time:    24.066s
03:46:41.133      Loader.versioning.XUnitWrapper                   Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    20.336s
03:46:41.133      managed.Compilation.XUnitWrapper                 Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    55.609s
03:46:41.133      readytorun.tests.XUnitWrapper                    Total:     6, Errors: 0, Failed: 0, Skipped: 0, Time:    41.859s
03:46:41.133      reflection.DefaultInterfaceMethods.XUnitWrapper  Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    35.479s
03:46:41.133      reflection.ldtoken.XUnitWrapper                  Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:    13.232s
03:46:41.133      reflection.regression.XUnitWrapper               Total:     2, Errors: 0, Failed: 0, Skipped: 0, Time:    13.739s
03:46:41.133      reflection.Tier1Collectible.XUnitWrapper         Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    46.888s
03:46:41.133      Regressions.assemblyref.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:     9.073s
03:46:41.133      Regressions.common.XUnitWrapper                  Total:    15, Errors: 0, Failed: 0, Skipped: 0, Time:    90.268s
03:46:41.133      Regressions.coreclr.XUnitWrapper                 Total:    53, Errors: 0, Failed: 0, Skipped: 0, Time:   245.127s
03:46:41.134      Regressions.expl_double.XUnitWrapper             Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    16.704s
03:46:41.134      tracing.eventactivityidcontrol.XUnitWrapper      Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    44.236s
03:46:41.134      tracing.eventlistener.XUnitWrapper               Total:     1, Errors: 0, Failed: 0, Skipped: 0, Time:    12.722s
03:46:41.134      tracing.eventsourcetrace.XUnitWrapper.dll        Total:     0
03:46:41.134      tracing.tracevalidation.XUnitWrapper             Total:     3, Errors: 0, Failed: 0, Skipped: 0, Time:    31.859s
03:46:41.134                                                              -----          -          -           -        ----------
03:46:41.134                                                 GRAND TOTAL: 11701          0          0           0        23690.903s (2692.075s)
03:46:42.211 
03:46:42.211 Build succeeded.
03:46:42.212     0 Warning(s)
03:46:42.212     0 Error(s)
03:46:42.214 
03:46:42.214 Time Elapsed 00:44:55.97
03:46:42.325 RUNTEST: Test run successful. Refer to the log files for details:
03:46:42.325     D:\j\workspace\x64_checked_w---1cba8152\tests\..\bin\Logs\TestRun_Windows_NT__x64__Checked.html
03:46:42.326     D:\j\workspace\x64_checked_w---1cba8152\tests\..\bin\Logs\TestRun_Windows_NT__x64__Checked.xml

@AndyAyersMS
Copy link
Member

Test build time goes from 165 min to 30 min? Very nice indeed. It will be interesting to see what this does on Linux once it's working.

I wonder if we can express the partitioning a bit more organically so that as new test directories are added they don't get inadvertently left out.

@4creators
Copy link
Author

4creators commented Mar 24, 2018

I wonder if we can express the partitioning a bit more organically so that as new test directories are added they don't get inadvertently left out.

After investigating the reasons for slow build I think it would be very helpful if all test projects structure will be rewritten to use large projects with batch build MSBuild feature what could reduce build time even further - my guess is that to half of what we have with this workaround ~15 - 20 min. MSBuild batch build feature is used now as well but in a different way.

If we use this path than it would be much easier to add tests and keep them in the build system. But it is a complete rewrite of current > 12k projects 😄

@4creators 4creators changed the title [WIP] Improve Windows test build performance by building projects in groups Improve Windows test build performance by building projects in groups - 4x less memory 326% faster build. Mar 24, 2018
@4creators
Copy link
Author

@RussKeldorph @AndyAyersMS @weshaggard @jkotas PTAL

PR is ready for review - it affects Windows only but improvements are so large and better than expected that it could be worth merging without Unix test build port which anyway is not used in CI as all tests are built on Windows.

@AndyAyersMS
Copy link
Member

Most of the jit test project files are simple and very stylized. So there's a good chance we can write a program to revise the project files as needed. For instance there is some simple rewriting in CheckProjects.

@4creators
Copy link
Author

there's a good chance we can write a program to revise the project files as needed

Agree, this work has to be done programmatically or with scripting.

@sdmaclea
Copy link

Looks like it would be trivial to enable for Linux too. I do not have time before ZBB though

@4creators
Copy link
Author

Looks like it would be trivial to enable for Linux too. I do not have time before ZBB though

True and I have the same time problem

@mmitche
Copy link
Member

mmitche commented Mar 27, 2018

Oh man this is awesome.

set __msbuildWrn=/flp1:WarningsOnly;LogFile="%__BuildWrn%";Append=!__AppendToLog!
set __msbuildErr=/flp2:ErrorsOnly;LogFile="%__BuildErr%";Append=!__AppendToLog!

set TestBuildSlice=%%G
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Any reason you aren't passing this as a property instead of depending on environment variable?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Both are possible but for me it is more clear code if it remains environment variable which like property passed on MSBuild commandline will be available during project build, however, commandline is already 233 characters long so I decided to not pass it that way while having very same effect.

If that style is not expected in build scripts I am open to any changes which will suit the team

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was looking at the command line to try and figure out how you split these and I didn't find it and then realized it was happening because of the env variable. I generally try to avoid env variables in build scripts/projects because it is harder to reproduce and diagnose. In this case I don't have a strong opinion though it is just a general principle.

Copy link
Author

@4creators 4creators Mar 27, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If it is general principle and you have had problem decoding usage of variable than I think it should be passed via command line. Would it be fine to fixup this in follow PR?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be fine to fixup this in follow PR?

Yes that is fine with me.

@weshaggard
Copy link
Member

While the performance improvments look great and I'm cool with working around this issue I share the worry with @AndyAyersMS about tests getting missed because we don't maintain this file and include them. The maintenance of this worries me some.

@sdmaclea
Copy link

One approach would be to base the bucket on a few characters of a hash of the project name. I would use 256 buckets based on two characters of the md5.

Maybe the test build project could be built and assign the groups. Or perhaps the test groups could be included?

@weshaggard
Copy link
Member

Ideally it we could always wildcard all the test projects and then do the partitioning dynamically. Perhaps a target that generates this partition group and then does the build.

@4creators
Copy link
Author

4creators commented Mar 27, 2018

tests getting missed because we don't maintain this file and include them. The maintenance of this worries me some.

@weshaggard @AndyAyersMS @sdmaclea

The current groups were created by hand after tedious testing to balance load for each group.

I entirely agree that we need better mechanism for group creation and the solution which I would prefer could be based on splitting in MSBuild collection of all globbed projects into equal "sized" (by build time) groups and use them during build. The hard part here is that projects need to be evaluated to a level where MSBuild would be aware to which priority they belong.

There are still other optimizations possible including one I have discussed with @AndyAyersMS where we could reduce number of projects by roughly 3 orders of magnitude from > 12k to 16 and build individual executables and startup scripts using batch build. Then getting project built would require instead of creating new project just inclusion of files into existing large project.

Another solution, albeit less efficient, could be based on programmatic or script based generation of of dirs.proj file once new project with tests is added.

I would use 256 buckets based on two characters of the md5

Every startup of the whole MSBuild node tree is quite time consuming not only due to CLR and MSBuild startup costs but due to first evaluation of the whole common projects structure, globbing etc. We do not know currently where optimum lies. For instance 16 groups for inner loop build is too much.

Anyway, if developer adds new test he/she should always check if it is active - tests are run. If we provide clear documentation and instructions even in this shape inclusion of new projects should make anyone with basic knowledge of MSBuild capable to include project into build.

@4creators
Copy link
Author

Perhaps a target that generates this partition group and then does the build

This is one option I have been thinking about. However, the most tempting one is to rewrite whole project system from > 12k projects down to number of groups we need. This should further significantly decrease build time.

@4creators
Copy link
Author

4creators commented Mar 27, 2018

@weshaggard

Due to ZBB and my everyday work assignments I am very tight on time during current two weeks. I hope you could agree to commit this PR in current or close to current state and I would follow with improvements after 8th April.

In current state we reduce test time for all HW intrinsic work from 4,5 to less than 2h - we run jitstress jobs on every PR we work on.

@weshaggard
Copy link
Member

@4creators We really appreciate all the efforts you put in on improving our infrastructure.

Due to ZBB and my everyday work assignments I am very tight on time during current two weeks. I hope you could agree to commit this PR in current or close to current state and I would follow with improvements after 8th April.

I don't have any concerns with this going in but I don't actively work in this repo so others should chime in. @RussKeldorph @AndyAyersMS @BruceForstall any issues with this going in?

@danmoseley
Copy link
Member

This is a tremendous improvement @4creators . thank you.

@RussKeldorph
Copy link

This is pretty ugly, but it will save so many resources that it's hard to resist taking it immediately. Hopefully we get time to refactor the test projects or find some better fix soon.

@rainersigwald FYI.

Copy link

@RussKeldorph RussKeldorph left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks a lot for this, @4creators.

@AndyAyersMS
Copy link
Member

Yes I think we can take this as is and work on a more comprehensive fix later.

@4creators thanks much. Can you open a follow up issue for a revised version that addresses the concerns raised above?

@weshaggard weshaggard merged commit 1cb3704 into dotnet:master Mar 28, 2018
@4creators 4creators deleted the testbuild branch March 28, 2018 01:53
@4creators
Copy link
Author

@AndyAyersMS Issue #17282 tracks the code review feedback.

@BruceForstall
Copy link

@4creators It looks like this change caused a failure in the ARM Pri-1 build with these failures:

Tests.lst=csgen.1.cmd_647, , , Smrt00000001, , # hosting\stress\testset1\csgen.1\csgen.1.cmd  CATS: EXPECTED_PASS;Pri1
Tests.lst=simple1.cmd_6444, , , Smrt00000001, , # hosting\stress\testset1\simple1\simple1.cmd  CATS: EXPECTED_PASS;Pri1
Tests.lst=csgen.2.cmd_11275, , , Smrt00000001, , # hosting\stress\testset1\csgen.2\csgen.2.cmd  CATS: EXPECTED_PASS;Pri1

https://ci.dot.net/job/dotnet_coreclr/job/master/job/arm_cross_checked_windows_nt_tst/882/artifact/bin/tests/Windows_NT.arm.Checked/Smarty.run.0/Smarty.0.fail.smrt/*view*/

It looks like the tests\src\hosting directory doesn't get built at all?

@4creators
Copy link
Author

@BruceForstall Investigating

@BruceForstall
Copy link

@4creators I've already submitted a PR that should fix this: #17322

4creators added a commit to dotnetrt/coreclr that referenced this pull request Apr 21, 2018
…fore file

Fixes #17503

The error is caused by both:

1. Unnecessary usage of 'managed_test_build' semaphore file which is incorrectly
   set after /t:BatchRestorePackages build target and prevents managed test build
   which is invoked after semaphore alredy exists
2. Masked by the above error is a wrong condition in dirs.proj non-windows test build
   which was introduced by PR dotnet#17161 and which prevented unix build due to missing
   dotnet#17161 group build port to unix
sdmaclea added a commit to sdmaclea/coreclr that referenced this pull request Apr 25, 2018
sdmaclea added a commit to sdmaclea/coreclr that referenced this pull request May 3, 2018
BruceForstall pushed a commit that referenced this pull request May 4, 2018
* Split unix test builds in slices

Ports #17161 to linux

* Address review feedback
jashook pushed a commit to jashook/coreclr that referenced this pull request May 11, 2018
* Split unix test builds in slices

Ports dotnet#17161 to linux

* Address review feedback
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants