[IMPALA-3421] Create codegen object time is counted on first operator that calls GetCodegen()

• Type: Bug
• Status: Resolved
• Priority: Minor
• Resolution: Duplicate
• Affects Version/s: Impala 2.3.0
• Component/s: Backend
• Labels: codegen
• Target Version: Product Backlog
• Assignee: Tim Armstrong
• Reporter: Juan Yu
• Created: 25/Apr/16 20:30
• Updated: 17/Oct/16 21:04
• Resolved: 17/Oct/16 21:04

Description

codegen object is created at the first time GetCodegen() is called (per fragment).
and the time is counted on caller's total_time_counter.
The profile has a separate section for codegen that already includes the initialize codegen object time (PrepareTime part). including it in operator again is confusion.
Example 1,
Query "select * from small_trip" takes "Query Timeline: 108.293ms". 86ms is spent on codegen.

Summary:
Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail
-----------------------------------------------------------------------------------------------------------
00:SCAN HDFS 1 89.671ms 89.671ms 2 -1 124.00 KB -1.00 B default.small_trip

CodeGen:(Total: 86.066ms, non-child: 86.066ms, % non-child: 100.00%)

• CodegenTime: 839.000ns
• CompileTime: 362.000ns
• LoadTime: 0.000ns
• ModuleBitcodeSize: 1.50 MB (1568624)
• NumFunctions: 0 (0)
• NumInstructions: 0 (0)
• OptimizationTime: 0.000ns
• PrepareTime: 85.510ms
  HDFS_SCAN_NODE (id=0):(Total: 89.671ms, non-child: 89.671ms, % non-child: 100.00%)
  ExecOption: Expr Evaluation Codegen Disabled, Codegen enabled: 0 out of 1
  Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/215.00 B
  Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0%
  File Formats: TEXT/NONE:1

codegen initialize time is added to HDFS_SCAN_NODE

Example 2:
Query "select count from small_trip" takes "Query Timeline: 298.401ms"

Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail
----------------------------------------------------------------------------------------------------------
01:AGGREGATE 1 87.240ms 87.240ms 1 1 12.00 KB -1.00 B FINALIZE
00:SCAN HDFS 1 3.676ms 3.676ms 2 -1 8.00 KB -1.00 B default.small_trip

CodeGen:(Total: 229.576ms, non-child: 229.576ms, % non-child: 100.00%)

• CodegenTime: 360.192us
• CompileTime: 542.173us
• LoadTime: 0.000ns
• ModuleBitcodeSize: 1.50 MB (1568624)
• NumFunctions: 293 (293)
• NumInstructions: 2.42K (2419)
• OptimizationTime: 142.157ms
• PrepareTime: 86.293ms
  AGGREGATION_NODE (id=1):(Total: 90.916ms, non-child: 87.240ms, % non-child: 95.96%)
  ExecOption: Codegen Enabled
• BuildTime: 1.306us

AGGREGATION_NODE execution time actually takes just a few ms.

I think it's better to not include codegen object initialize time on operator whos the first one calls GetCodegen().

Issue Links

• is blocked by: IMPALA-3638 Remove lazy creation of LLVM codegen module