[CodeGen] long compilation time with VLIWMachineScheduler

[dfszabo]

The compilation of the example code takes a lot of time in the scheduling pass for Hexagon. In our downstream backend, which use VLIWMachineScheduler it is even worse (85+%), therefore the cause should be in the target independent part.

===-------------------------------------------------------------------------===
                          Pass execution timing report
===-------------------------------------------------------------------------===
  Total Execution Time: 144.8409 seconds (144.9222 wall clock)

   ---User Time---   --System Time--   --User+System--   ---Wall Time---  --- Name ---
  74.5014 ( 51.5%)   0.0405 ( 21.3%)  74.5418 ( 51.5%)  74.5774 ( 51.5%)  Machine Instruction Scheduler
  25.3194 ( 17.5%)   0.0118 (  6.2%)  25.3312 ( 17.5%)  25.3545 ( 17.5%)  Hexagon bit simplification
  17.2195 ( 11.9%)   0.0041 (  2.1%)  17.2236 ( 11.9%)  17.2288 ( 11.9%)  Hexagon generate "insert" instructions
  10.9911 (  7.6%)   0.0000 (  0.0%)  10.9911 (  7.6%)  10.9959 (  7.6%)  Hexagon Loop Rescheduling
   8.2689 (  5.7%)   0.0000 (  0.0%)   8.2689 (  5.7%)   8.2727 (  5.7%)  Hexagon constant-extender optimization
   6.1502 (  4.3%)   0.0161 (  8.5%)   6.1663 (  4.3%)   6.1687 (  4.3%)  Prologue/Epilogue Insertion & Frame Finalization
   0.5480 (  0.4%)   0.0365 ( 19.2%)   0.5845 (  0.4%)   0.5845 (  0.4%)  Hexagon RDF optimizations
   0.4602 (  0.3%)   0.0324 ( 17.1%)   0.4926 (  0.3%)   0.4927 (  0.3%)  Optimize addressing mode of load/store
   0.4537 (  0.3%)   0.0120 (  6.3%)   0.4657 (  0.3%)   0.4658 (  0.3%)  Hexagon DAG->DAG Pattern Instruction Selection

test_long_compilation.zip

[kparzysz-quic]

I ran operf on it and the time is spent in

llvm::ConvergingVLIWScheduler::VLIWSchedBoundary::init(llvm::VLIWMachineScheduler*, llvm::TargetSchedModel const*)

That function computes the height and depth of every SUnit in the DAG. Maybe it can be sped up a bit.

[llvmbot]

@llvm/issue-subscribers-backend-hexagon

Details

The compilation of the example code takes a lot of time in the scheduling pass for Hexagon. In our downstream backend, which use VLIWMachineScheduler it is even worse (85+%), therefore the cause should be in the target independent part. ``` ===-------------------------------------------------------------------------=== Pass execution timing report ===-------------------------------------------------------------------------=== Total Execution Time: 144.8409 seconds (144.9222 wall clock)

---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name ---
74.5014 ( 51.5%) 0.0405 ( 21.3%) 74.5418 ( 51.5%) 74.5774 ( 51.5%) Machine Instruction Scheduler
25.3194 ( 17.5%) 0.0118 ( 6.2%) 25.3312 ( 17.5%) 25.3545 ( 17.5%) Hexagon bit simplification
17.2195 ( 11.9%) 0.0041 ( 2.1%) 17.2236 ( 11.9%) 17.2288 ( 11.9%) Hexagon generate "insert" instructions
10.9911 ( 7.6%) 0.0000 ( 0.0%) 10.9911 ( 7.6%) 10.9959 ( 7.6%) Hexagon Loop Rescheduling
8.2689 ( 5.7%) 0.0000 ( 0.0%) 8.2689 ( 5.7%) 8.2727 ( 5.7%) Hexagon constant-extender optimization
6.1502 ( 4.3%) 0.0161 ( 8.5%) 6.1663 ( 4.3%) 6.1687 ( 4.3%) Prologue/Epilogue Insertion & Frame Finalization
0.5480 ( 0.4%) 0.0365 ( 19.2%) 0.5845 ( 0.4%) 0.5845 ( 0.4%) Hexagon RDF optimizations
0.4602 ( 0.3%) 0.0324 ( 17.1%) 0.4926 ( 0.3%) 0.4927 ( 0.3%) Optimize addressing mode of load/store
0.4537 ( 0.3%) 0.0120 ( 6.3%) 0.4657 ( 0.3%) 0.4658 ( 0.3%) Hexagon DAG->DAG Pattern Instruction Selection

[test_long_compilation.zip](https://github.com/llvm/llvm-project/files/12575134/test_long_compilation.zip)

</details>

[dfszabo]

I ran operf on it and the time is spent in

llvm::ConvergingVLIWScheduler::VLIWSchedBoundary::init(llvm::VLIWMachineScheduler*, llvm::TargetSchedModel const*)

That function computes the height and depth of every SUnit in the DAG. Maybe it can be sped up a bit.

Thank you, this really helped to start the investigation. Surprisingly the problem is with getBBSize() function. It iterates through the whole BB to acquire the size. The real problem is that this init function is called twice for each scheduling region and in the test there is 8000 call therefore that many sched region and the BB size is around 50 000, so there will be like 1,6 billion iteration over the BB overall since this getBBSize function called twice in init and this eats up most of the time. A straight forward improvement is to save getBBSize() result into a variable, since its called twice in the init function.

Time report without the change:

===-------------------------------------------------------------------------===
                          Pass execution timing report
===-------------------------------------------------------------------------===
  Total Execution Time: 73.5874 seconds (73.6201 wall clock)

   ---User Time---   --System Time--   --User+System--   ---Wall Time---  --- Name ---
  24.8764 ( 33.9%)   0.0001 (  0.1%)  24.8765 ( 33.8%)  24.8826 ( 33.8%)  Machine Instruction Scheduler
  17.2754 ( 23.5%)   0.0000 (  0.0%)  17.2754 ( 23.5%)  17.2819 ( 23.5%)  Hexagon bit simplification
   9.5315 ( 13.0%)   0.0000 (  0.0%)   9.5315 ( 13.0%)   9.5336 ( 12.9%)  Hexagon generate "insert" instructions
   9.2437 ( 12.6%)   0.0003 (  0.3%)   9.2440 ( 12.6%)   9.2588 ( 12.6%)  Hexagon Loop Rescheduling

Time report with saving the size to a variable:

===-------------------------------------------------------------------------===
                          Pass execution timing report
===-------------------------------------------------------------------------===
  Total Execution Time: 59.9060 seconds (59.9134 wall clock)

   ---User Time---   --System Time--   --User+System--   ---Wall Time---  --- Name ---
  17.0739 ( 28.6%)   0.0000 (  0.0%)  17.0739 ( 28.5%)  17.0759 ( 28.5%)  Hexagon bit simplification
  12.4662 ( 20.9%)   0.0001 (  0.1%)  12.4663 ( 20.8%)  12.4672 ( 20.8%)  Machine Instruction Scheduler
   9.7697 ( 16.3%)   0.0000 (  0.0%)   9.7697 ( 16.3%)   9.7705 ( 16.3%)  Hexagon generate "insert" instructions
   8.4727 ( 14.2%)   0.0000 (  0.0%)   8.4727 ( 14.1%)   8.4750 ( 14.1%)  Hexagon Loop Rescheduling

Created a PR for the change: #66942