[InlineCost] Improve debugging experience by adding print about initial inlining cost

[yurai007]

To put more context for this patch, while playing with LLVM Inliner I ended up with 2 very similar code snippets causing very different inlining decisions.
Looking at --debug-only=inline-cost output didn't help in figuring out what happened:

Analyzing call of kh_put_oligonucleotide... (caller:generate_Count_For_Oligonucleotide)
NumConstantArgs: 0
NumConstantOffsetPtrArgs: 2
NumAllocaArgs: 1
NumConstantPtrCmps: 0
NumConstantPtrDiffs: 0
NumInstructionsSimplified: 45
NumInstructions: 141
SROACostSavings: 25
SROACostSavingsLost: 0
LoadEliminationCost: 0
ContainsNoDuplicateCall: 0
Cost: -14490
Threshold: 325

remark: 'kh_put_oligonucleotide' inlined into 'generate_Count_For_Oligonucleotide' with (cost=-14490, threshold=325) at callsite generate_Count_For_Oligonucleotide:22:20; [-Rpass=inline]

Analyzing call of kh_put_oligonucleotide... (caller:generate_Count_For_Oligonucleotide)
NumConstantArgs: 0
NumConstantOffsetPtrArgs: 2
NumAllocaArgs: 1
NumConstantPtrCmps: 0
NumConstantPtrDiffs: 0
NumInstructionsSimplified: 45
NumInstructions: 141
SROACostSavings: 25
SROACostSavingsLost: 0
LoadEliminationCost: 0
ContainsNoDuplicateCall: 0
Cost: 510
Threshold: 325

remark: 'kh_put_oligonucleotide' not inlined into 'generate_Count_For_Oligonucleotide' because too costly to inline (cost=510, threshold=325) [-Rpass-missed=inline]

For both cases output is exactly same except final Cost value. It took me a while to realize that it's not unusual that major part of Cost is initial cost coming from various bonuses and penalties.
In my opinion it would be nice to emphasis this fact by printing initial cost value at the time when it's computed.
After such change I believe that debug output is more clear about what is source of final very low (or high in case of penalties) Cost value:

Analyzing call of kh_put_oligonucleotide... (caller:generate_Count_For_Oligonucleotide)
Initial cost: -15045
NumConstantArgs: 0
NumConstantOffsetPtrArgs: 2
NumAllocaArgs: 1
NumConstantPtrCmps: 0
NumConstantPtrDiffs: 0
NumInstructionsSimplified: 45
NumInstructions: 141
SROACostSavings: 25
SROACostSavingsLost: 0
LoadEliminationCost: 0
ContainsNoDuplicateCall: 0
Cost: -14490
Threshold: 325

remark: 'kh_put_oligonucleotide' inlined into 'generate_Count_For_Oligonucleotide' with (cost=-14490, threshold=325) at callsite generate_Count_For_Oligonucleotide:22:20; [-Rpass=inline]

Analyzing call of kh_put_oligonucleotide... (caller:generate_Count_For_Oligonucleotide)
Initial cost: -45
NumConstantArgs: 0
NumConstantOffsetPtrArgs: 2
NumAllocaArgs: 1
NumConstantPtrCmps: 0
NumConstantPtrDiffs: 0
NumInstructionsSimplified: 45
NumInstructions: 141
SROACostSavings: 25
SROACostSavingsLost: 0
LoadEliminationCost: 0
ContainsNoDuplicateCall: 0
Cost: 510
Threshold: 325

remark: 'kh_put_oligonucleotide' not inlined into 'generate_Count_For_Oligonucleotide' because too costly to inline (cost=510, threshold=325) [-Rpass-missed=inline]

Finally, although one may argue that with --print-instruction-comments=1 we can (kind of) deduce initial cost looking at cost before first analyzed instruction,
passing to Inliner --print-instruction-comments=1 produce much more verbose output (in comparison to normal debug one) and since it's dumped at the end on analysis
doesn't give clue when initial Cost value was set.

[yurai007]

llvm/lib/Analysis/InlineCost.cpp

985

It's not camel cased (in opposite to stats like NumConstantArgs) to indicate that's just normal debug print like "Analyzing call..." one.

[nikic]

Looks reasonable

[yurai007]

@nikic: Thanks for the review!

llvm/lib/Analysis/InlineCost.cpp

InlineResult onAnalysisStart() override {
     // will be gone after inlining.
     addCost(-getCallsiteCost(this->CandidateCall, DL));
 
     // If this function uses the coldcc calling convention, prefer not to inline
     // it.
     if (F.getCallingConv() == CallingConv::Cold)
       Cost += InlineConstants::ColdccPenalty;
 
+    LLVM_DEBUG(dbgs() << "      Initial cost: " << Cost << "\n");
+
     // Check if we're done. This can happen due to bonuses and penalties.
     if (Cost >= Threshold && !ComputeFullInlineCost)
       return InlineResult::failure("high cost");
 
     return InlineResult::success();
   }
 
 public:

llvm/test/Transforms/Inline/X86/extractvalue.ll

 ; RUN: opt < %s -inline -inline-threshold=0 -debug-only=inline-cost -print-instruction-comments -S -mtriple=x86_64-unknown-linux-gnu 2>&1 | FileCheck %s
 ; RUN: opt < %s -passes='cgscc(inline)' -inline-threshold=0 -debug-only=inline-cost -print-instruction-comments -S -mtriple=x86_64-unknown-linux-gnu 2>&1 | FileCheck %s
 ; REQUIRES: asserts
 
 target datalayout = "e-m:e-i64:64-f80:128-n8:16:32:64-S128"
 target triple = "x86_64-unknown-unknown"
 
 ; Check that extractvalue's are free.
 
 ; CHECK: Analyzing call of callee... (caller:caller_range)
+; CHECK-NEXT: Initial cost: -35
 ; CHECK-NEXT: define i32 @callee({ i32, i32 } %arg) {
 ; CHECK-NEXT: ; cost before = -35, cost after = -35, threshold before = 0, threshold after = 0, cost delta = 0
 ; CHECK-NEXT:   %r = extractvalue { i32, i32 } %arg, 0
 ; CHECK-NEXT: ; cost before = -35, cost after = -35, threshold before = 0, threshold after = 0, cost delta = 0
 ; CHECK-NEXT:   ret i32 %r
 ; CHECK-NEXT: }
 
 define i32 @callee({i32, i32} %arg) {
   %r = extractvalue {i32, i32} %arg, 0
   ret i32 %r
 }
 
 define i32 @caller_range({i32, i32} %arg) {
   %r = call i32 @callee({i32, i32} %arg)
   ret i32 %r
 }

llvm/test/Transforms/Inline/X86/insertvalue.ll

 ; RUN: opt < %s -inline -inline-threshold=0 -debug-only=inline-cost -print-instruction-comments -S -mtriple=x86_64-unknown-linux-gnu 2>&1 | FileCheck %s
 ; RUN: opt < %s -passes='cgscc(inline)' -inline-threshold=0 -debug-only=inline-cost -print-instruction-comments -S -mtriple=x86_64-unknown-linux-gnu 2>&1 | FileCheck %s
 ; REQUIRES: asserts
 
 target datalayout = "e-m:e-i64:64-f80:128-n8:16:32:64-S128"
 target triple = "x86_64-unknown-unknown"
 
 ; Check that insertvalue's aren't free.
 
 ; CHECK: Analyzing call of callee... (caller:caller_range)
+; CHECK-NEXT: Initial cost: -40
 ; CHECK-NEXT: define { i32, i32 } @callee({ i32, i32 } %arg, i32 %arg1) {
 ; CHECK-NEXT: ; cost before = -40, cost after = -35, threshold before = 0, threshold after = 0, cost delta = 5
 ; CHECK-NEXT:   %r = insertvalue { i32, i32 } %arg, i32 %arg1, 0
 ; CHECK-NEXT: ; cost before = -35, cost after = -35, threshold before = 0, threshold after = 0, cost delta = 0
 ; CHECK-NEXT:   ret { i32, i32 } %r
 ; CHECK-NEXT: }
 
 define {i32, i32} @callee({i32, i32} %arg, i32 %arg1) {
   %r = insertvalue {i32, i32} %arg, i32 %arg1, 0
   ret {i32, i32} %r
 }
 
 define {i32, i32} @caller_range({i32, i32} %arg, i32 %arg1) {
   %r = call {i32, i32} @callee({i32, i32} %arg, i32 %arg1)
   ret {i32, i32} %r
 }