private void logQueryTimeline(QueryInfo queryInfo) {
try {
QueryStats queryStats = queryInfo.getQueryStats();
DateTime queryStartTime = queryStats.getCreateTime();
DateTime queryEndTime = queryStats.getEndTime();
// query didn't finish cleanly
if (queryStartTime == null || queryEndTime == null) {
return;
}
// planning duration -- start to end of planning
Duration planning = queryStats.getTotalPlanningTime();
if (planning == null) {
planning = new Duration(0, MILLISECONDS);
}
List<StageInfo> stages = StageInfo.getAllStages(queryInfo.getOutputStage());
// long lastSchedulingCompletion = 0;
long firstTaskStartTime = queryEndTime.getMillis();
long lastTaskStartTime = queryStartTime.getMillis() + planning.toMillis();
long lastTaskEndTime = queryStartTime.getMillis() + planning.toMillis();
for (StageInfo stage : stages) {
// only consider leaf stages
if (!stage.getSubStages().isEmpty()) {
continue;
}
for (TaskInfo taskInfo : stage.getTasks()) {
TaskStats taskStats = taskInfo.getStats();
DateTime firstStartTime = taskStats.getFirstStartTime();
if (firstStartTime != null) {
firstTaskStartTime = Math.min(firstStartTime.getMillis(), firstTaskStartTime);
}
DateTime lastStartTime = taskStats.getLastStartTime();
if (lastStartTime != null) {
lastTaskStartTime = Math.max(lastStartTime.getMillis(), lastTaskStartTime);
}
DateTime endTime = taskStats.getEndTime();
if (endTime != null) {
lastTaskEndTime = Math.max(endTime.getMillis(), lastTaskEndTime);
}
}
}
Duration elapsed = millis(queryEndTime.getMillis() - queryStartTime.getMillis());
Duration scheduling =
millis(firstTaskStartTime - queryStartTime.getMillis() - planning.toMillis());
Duration running = millis(lastTaskEndTime - firstTaskStartTime);
Duration finishing = millis(queryEndTime.getMillis() - lastTaskEndTime);
log.info(
"TIMELINE: Query %s :: elapsed %s :: planning %s :: scheduling %s :: running %s :: finishing %s :: begin %s :: end %s",
queryInfo.getQueryId(),
elapsed,
planning,
scheduling,
running,
finishing,
queryStartTime,
queryEndTime);
} catch (Exception e) {
log.error(e, "Error logging query timeline");
}
}
@Override
public RecordCursor cursor() {
Builder table = InMemoryRecordSet.builder(TASK_TABLE);
for (TaskInfo taskInfo : taskManager.getAllTaskInfo()) {
TaskStats stats = taskInfo.getStats();
table.addRow(
nodeId,
taskInfo.getTaskId().toString(),
taskInfo.getTaskId().getStageId().toString(),
taskInfo.getTaskId().getQueryId().toString(),
taskInfo.getState().toString(),
(long) stats.getTotalDrivers(),
(long) stats.getQueuedDrivers(),
(long) stats.getRunningDrivers(),
(long) stats.getCompletedDrivers(),
toMillis(stats.getTotalScheduledTime()),
toMillis(stats.getTotalCpuTime()),
toMillis(stats.getTotalUserTime()),
toMillis(stats.getTotalBlockedTime()),
toBytes(stats.getRawInputDataSize()),
stats.getRawInputPositions(),
toBytes(stats.getProcessedInputDataSize()),
stats.getProcessedInputPositions(),
toBytes(stats.getOutputDataSize()),
stats.getOutputPositions(),
toTimeStamp(stats.getCreateTime()),
toTimeStamp(stats.getFirstStartTime()),
toTimeStamp(taskInfo.getLastHeartbeat()),
toTimeStamp(stats.getEndTime()));
}
return table.build().cursor();
}