Search in sources :

Example 6 with TaskStats

use of io.trino.operator.TaskStats in project trino by trinodb.

the class QueryMonitor method logQueryTimeline.

private static 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
        long planning = queryStats.getPlanningTime().toMillis();
        // Time spent waiting for required no. of worker nodes to be present
        long waiting = queryStats.getResourceWaitingTime().toMillis();
        List<StageInfo> stages = getAllStages(queryInfo.getOutputStage());
        // long lastSchedulingCompletion = 0;
        long firstTaskStartTime = queryEndTime.getMillis();
        long lastTaskStartTime = queryStartTime.getMillis() + planning;
        long lastTaskEndTime = queryStartTime.getMillis() + planning;
        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 = max(lastStartTime.getMillis(), lastTaskStartTime);
                }
                DateTime endTime = taskStats.getEndTime();
                if (endTime != null) {
                    lastTaskEndTime = max(endTime.getMillis(), lastTaskEndTime);
                }
            }
        }
        long elapsed = max(queryEndTime.getMillis() - queryStartTime.getMillis(), 0);
        long scheduling = max(firstTaskStartTime - queryStartTime.getMillis() - planning, 0);
        long running = max(lastTaskEndTime - firstTaskStartTime, 0);
        long finishing = max(queryEndTime.getMillis() - lastTaskEndTime, 0);
        logQueryTimeline(queryInfo.getQueryId(), queryInfo.getSession().getTransactionId().map(TransactionId::toString).orElse(""), elapsed, planning, waiting, scheduling, running, finishing, queryStartTime, queryEndTime);
    } catch (Exception e) {
        log.error(e, "Error logging query timeline");
    }
}
Also used : TaskInfo(io.trino.execution.TaskInfo) QueryStats(io.trino.execution.QueryStats) StageInfo(io.trino.execution.StageInfo) TaskStats(io.trino.operator.TaskStats) DateTime(org.joda.time.DateTime) TransactionId(io.trino.transaction.TransactionId)

Example 7 with TaskStats

use of io.trino.operator.TaskStats in project trino by trinodb.

the class StageStateMachine method getBasicStageStats.

public BasicStageStats getBasicStageStats(Supplier<Iterable<TaskInfo>> taskInfosSupplier) {
    Optional<StageInfo> finalStageInfo = this.finalStageInfo.get();
    if (finalStageInfo.isPresent()) {
        return finalStageInfo.get().getStageStats().toBasicStageStats(finalStageInfo.get().getState());
    }
    // stage state must be captured first in order to provide a
    // consistent view of the stage. For example, building this
    // information, the stage could finish, and the task states would
    // never be visible.
    StageState state = stageState.get();
    boolean isScheduled = state == RUNNING || state == StageState.PENDING || state.isDone();
    List<TaskInfo> taskInfos = ImmutableList.copyOf(taskInfosSupplier.get());
    int totalDrivers = 0;
    int queuedDrivers = 0;
    int runningDrivers = 0;
    int completedDrivers = 0;
    long cumulativeUserMemory = 0;
    long failedCumulativeUserMemory = 0;
    long userMemoryReservation = 0;
    long totalMemoryReservation = 0;
    long totalScheduledTime = 0;
    long failedScheduledTime = 0;
    long totalCpuTime = 0;
    long failedCpuTime = 0;
    long physicalInputDataSize = 0;
    long physicalInputPositions = 0;
    long physicalInputReadTime = 0;
    long internalNetworkInputDataSize = 0;
    long internalNetworkInputPositions = 0;
    long rawInputDataSize = 0;
    long rawInputPositions = 0;
    boolean fullyBlocked = true;
    Set<BlockedReason> blockedReasons = new HashSet<>();
    for (TaskInfo taskInfo : taskInfos) {
        TaskState taskState = taskInfo.getTaskStatus().getState();
        TaskStats taskStats = taskInfo.getStats();
        totalDrivers += taskStats.getTotalDrivers();
        queuedDrivers += taskStats.getQueuedDrivers();
        runningDrivers += taskStats.getRunningDrivers();
        completedDrivers += taskStats.getCompletedDrivers();
        cumulativeUserMemory += taskStats.getCumulativeUserMemory();
        if (taskState == TaskState.FAILED) {
            failedCumulativeUserMemory += taskStats.getCumulativeUserMemory();
        }
        long taskUserMemory = taskStats.getUserMemoryReservation().toBytes();
        long taskRevocableMemory = taskStats.getRevocableMemoryReservation().toBytes();
        userMemoryReservation += taskUserMemory;
        totalMemoryReservation += taskUserMemory + taskRevocableMemory;
        totalScheduledTime += taskStats.getTotalScheduledTime().roundTo(NANOSECONDS);
        totalCpuTime += taskStats.getTotalCpuTime().roundTo(NANOSECONDS);
        if (taskState == TaskState.FAILED) {
            failedScheduledTime += taskStats.getTotalScheduledTime().roundTo(NANOSECONDS);
            failedCpuTime += taskStats.getTotalCpuTime().roundTo(NANOSECONDS);
        }
        if (!taskState.isDone()) {
            fullyBlocked &= taskStats.isFullyBlocked();
            blockedReasons.addAll(taskStats.getBlockedReasons());
        }
        physicalInputDataSize += taskStats.getPhysicalInputDataSize().toBytes();
        physicalInputPositions += taskStats.getPhysicalInputPositions();
        physicalInputReadTime += taskStats.getPhysicalInputReadTime().roundTo(NANOSECONDS);
        internalNetworkInputDataSize += taskStats.getInternalNetworkInputDataSize().toBytes();
        internalNetworkInputPositions += taskStats.getInternalNetworkInputPositions();
        if (fragment.getPartitionedSourceNodes().stream().anyMatch(TableScanNode.class::isInstance)) {
            rawInputDataSize += taskStats.getRawInputDataSize().toBytes();
            rawInputPositions += taskStats.getRawInputPositions();
        }
    }
    OptionalDouble progressPercentage = OptionalDouble.empty();
    if (isScheduled && totalDrivers != 0) {
        progressPercentage = OptionalDouble.of(min(100, (completedDrivers * 100.0) / totalDrivers));
    }
    return new BasicStageStats(isScheduled, totalDrivers, queuedDrivers, runningDrivers, completedDrivers, succinctBytes(physicalInputDataSize), physicalInputPositions, new Duration(physicalInputReadTime, NANOSECONDS).convertToMostSuccinctTimeUnit(), succinctBytes(internalNetworkInputDataSize), internalNetworkInputPositions, succinctBytes(rawInputDataSize), rawInputPositions, cumulativeUserMemory, failedCumulativeUserMemory, succinctBytes(userMemoryReservation), succinctBytes(totalMemoryReservation), new Duration(totalCpuTime, NANOSECONDS).convertToMostSuccinctTimeUnit(), new Duration(failedCpuTime, NANOSECONDS).convertToMostSuccinctTimeUnit(), new Duration(totalScheduledTime, NANOSECONDS).convertToMostSuccinctTimeUnit(), new Duration(failedScheduledTime, NANOSECONDS).convertToMostSuccinctTimeUnit(), fullyBlocked, blockedReasons, progressPercentage);
}
Also used : BlockedReason(io.trino.operator.BlockedReason) Duration(io.airlift.units.Duration) Duration.succinctDuration(io.airlift.units.Duration.succinctDuration) TaskStats(io.trino.operator.TaskStats) OptionalDouble(java.util.OptionalDouble) TableScanNode(io.trino.sql.planner.plan.TableScanNode) HashSet(java.util.HashSet)

Example 8 with TaskStats

use of io.trino.operator.TaskStats in project trino by trinodb.

the class AbstractOperatorBenchmark method runOnce.

@Override
protected Map<String, Long> runOnce() {
    Session session = testSessionBuilder().setSystemProperty("optimizer.optimize-hash-generation", "true").setTransactionId(this.session.getRequiredTransactionId()).build();
    MemoryPool memoryPool = new MemoryPool(DataSize.of(1, GIGABYTE));
    SpillSpaceTracker spillSpaceTracker = new SpillSpaceTracker(DataSize.of(1, GIGABYTE));
    TaskContext taskContext = new QueryContext(new QueryId("test"), DataSize.of(256, MEGABYTE), memoryPool, new TestingGcMonitor(), localQueryRunner.getExecutor(), localQueryRunner.getScheduler(), DataSize.of(256, MEGABYTE), spillSpaceTracker).addTaskContext(new TaskStateMachine(new TaskId(new StageId("query", 0), 0, 0), localQueryRunner.getExecutor()), session, () -> {
    }, false, false);
    CpuTimer cpuTimer = new CpuTimer();
    Map<String, Long> executionStats = execute(taskContext);
    CpuDuration executionTime = cpuTimer.elapsedTime();
    TaskStats taskStats = taskContext.getTaskStats();
    long inputRows = taskStats.getRawInputPositions();
    long inputBytes = taskStats.getRawInputDataSize().toBytes();
    long outputRows = taskStats.getOutputPositions();
    long outputBytes = taskStats.getOutputDataSize().toBytes();
    double inputMegaBytes = ((double) inputBytes) / MEGABYTE.inBytes();
    return ImmutableMap.<String, Long>builder().putAll(executionStats).put("elapsed_millis", executionTime.getWall().toMillis()).put("input_rows_per_second", (long) (inputRows / executionTime.getWall().getValue(SECONDS))).put("output_rows_per_second", (long) (outputRows / executionTime.getWall().getValue(SECONDS))).put("input_megabytes", (long) inputMegaBytes).put("input_megabytes_per_second", (long) (inputMegaBytes / executionTime.getWall().getValue(SECONDS))).put("wall_nanos", executionTime.getWall().roundTo(NANOSECONDS)).put("cpu_nanos", executionTime.getCpu().roundTo(NANOSECONDS)).put("user_nanos", executionTime.getUser().roundTo(NANOSECONDS)).put("input_rows", inputRows).put("input_bytes", inputBytes).put("output_rows", outputRows).put("output_bytes", outputBytes).buildOrThrow();
}
Also used : SpillSpaceTracker(io.trino.spiller.SpillSpaceTracker) TaskContext(io.trino.operator.TaskContext) TaskId(io.trino.execution.TaskId) QueryId(io.trino.spi.QueryId) StageId(io.trino.execution.StageId) QueryContext(io.trino.memory.QueryContext) TaskStats(io.trino.operator.TaskStats) TaskStateMachine(io.trino.execution.TaskStateMachine) TestingGcMonitor(io.airlift.stats.TestingGcMonitor) CpuTimer(io.airlift.stats.CpuTimer) CpuDuration(io.airlift.stats.CpuTimer.CpuDuration) Session(io.trino.Session) MemoryPool(io.trino.memory.MemoryPool)

Aggregations

TaskStats (io.trino.operator.TaskStats)8 Duration (io.airlift.units.Duration)2 TaskInfo (io.trino.execution.TaskInfo)2 BlockedReason (io.trino.operator.BlockedReason)2 TaskContext (io.trino.operator.TaskContext)2 HashSet (java.util.HashSet)2 DateTime (org.joda.time.DateTime)2 CpuTimer (io.airlift.stats.CpuTimer)1 CpuDuration (io.airlift.stats.CpuTimer.CpuDuration)1 TestingGcMonitor (io.airlift.stats.TestingGcMonitor)1 DataSize (io.airlift.units.DataSize)1 Duration.succinctDuration (io.airlift.units.Duration.succinctDuration)1 Session (io.trino.Session)1 QueryStats (io.trino.execution.QueryStats)1 StageId (io.trino.execution.StageId)1 StageInfo (io.trino.execution.StageInfo)1 TaskId (io.trino.execution.TaskId)1 TaskStateMachine (io.trino.execution.TaskStateMachine)1 TaskStatus (io.trino.execution.TaskStatus)1 MemoryPool (io.trino.memory.MemoryPool)1