[IMPALA-4613] Fragment total time regressed after IMPALA-4504

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: Impala 2.8.0
• Fix Version/s: Impala 2.8.0
• Component/s: Backend
• Assignee: Henry Robinson
• Reporter: Henry Robinson
• Created: 07/Dec/16 02:49
• Updated: 07/Dec/16 15:24
• Resolved: 07/Dec/16 15:24

Description

After IMPALA-4504, the last report profile is sent from PFE::Exec(). As the comment there says, all counters must go out of scope before the profile is sent so that the timer value is updated (on destruction of the scoped timer):

Status PlanFragmentExecutor::Exec() {
  DCHECK(opened_promise_.IsSet() && opened_promise_.Get().ok());
  SCOPED_TIMER(profile()->total_time_counter());
  Status status;
  {
    // Must go out of scope before FragmentComplete(), otherwise counter will not be
    // updated by time final profile is sent, and will always be 0.
    SCOPED_TIMER(ADD_TIMER(timings_profile_, EXEC_TIMER_NAME));
    status = ExecInternal();
  }
  if (!status.ok() && !status.IsCancelled() && !status.IsMemLimitExceeded()) {
    // Log error message in addition to returning in Status. Queries that do not fetch
    // results (e.g. insert) may not receive the message directly and can only retrieve
    // the log.
    runtime_state_->LogError(status.msg());
  }
  FragmentComplete(status);
  return status;
}