[IMPALA-6140] Unexplained gap between "All backends started" and "Rows available"

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Cannot Reproduce
• Affects Version/s: Impala 2.10.0
• Component/s: Distributed Exec
• Labels: profile
• Target Version: Product Backlog
• Epic Color: ghx-label-1
• Assignee: Unassigned
• Reporter: Tim Armstrong
• Created: 01/Nov/17 19:30
• Updated: 14/May/20 19:18
• Resolved: 14/May/20 19:18

Description

In the query timeline below there is a significant delay before rows are available.

    Query Timeline
      Query submitted: 305.17us (305173)
      Planning finished: 81ms (81195593)
      Submit for admission: 82ms (82781362)
      Completed admission: 83ms (83014912)
      Ready to start on 35 backends: 84ms (84726950)
      All 35 execution backends (35 fragment instances) started: 327ms (327067351)
      Rows available: 1.0m (60347008871)
      Unregister query: 7.5m (447851216220)

The exec summary doesn't have any evidence of slowness. I also looked at the rest of the profile and couldn't find any timers > 5s.

Operator       #Hosts   Avg Time   Max Time    #Rows  Est. #Rows   Peak Mem  Est. Peak Mem  Detail                
------------------------------------------------------------------------------------------------------------------
03:AGGREGATE        1    0.000ns    0.000ns        0           1  148.00 KB       10.00 MB  FINALIZE              
02:EXCHANGE         1  474.937ms  474.937ms       33           1          0              0  UNPARTITIONED         
01:AGGREGATE       34   64.749ms  453.860ms       33           1    1.24 MB       10.00 MB                        
00:SCAN HDFS       34    1s391ms    5s736ms  987.15K      12.96B   82.19 MB      176.00 MB  db.table 

One interesting data point is that we have anecdotal evidence that there were orphaned query fragments sending reports on this cluster.