/** * Formats the given milliseconds as {@code h:MM:ss.mmm (millis ms)}. * * @param millis the milliseconds to format * @param isProvideRaw whether to include the {@code (millis ms)} * @return the formatted milliseconds */ public static String formatDuration(long millis, boolean isProvideRaw) { return isProvideRaw ? String.format("%s (%d ms)", formatDuration(millis), millis) : formatDuration(millis); }
/** * Formats the given milliseconds as {@code h:MM:ss.mmm}. * * @param millis the milliseconds to format * @return the formatted milliseconds */ public static String formatDuration(long millis) { if (millis < 0) return "-" + formatDuration(-millis); long ms = millis % 1000; millis /= 1000; long s = millis % 60; millis /= 60; long m = millis % 60; millis /= 60; long h = millis % 60; return String.format("%d:%02d:%02d.%03d", h, m, s, ms); }
@SuppressWarnings("unused") public String toIntervalString(boolean isProvideRaw) { return String.format("(%s .. %s, p=%s)", Formats.formatDuration(this.getLowerEstimate(), isProvideRaw), Formats.formatDuration(this.getUpperEstimate(), isProvideRaw), Formats.formatPercentage(this.getCorrectnessProbability())); }
@Override public void add(PartialExecution partialExecution) { this.partialExecutions.add(partialExecution); if (this.logger.isInfoEnabled()) { this.logger.info( "Executed {} items in {} (estimated {}).", partialExecution.getAtomicExecutionGroups().size(), Formats.formatDuration(partialExecution.getMeasuredExecutionTime()), partialExecution.getOverallTimeEstimate(this.getConfiguration()) ); } }
numExecutedStages, Formats.formatDuration(finishTime - startTime, true));
@SuppressWarnings("unused") public String toGMeanString() { final long geometricMeanEstimate = this.getGeometricMeanEstimate(); final double dev = geometricMeanEstimate == 0 ? 0d : this.getUpperEstimate() / (double) geometricMeanEstimate; return String.format("(%s, d=%.1f, p=%s)", Formats.formatDuration(geometricMeanEstimate, true), dev, Formats.formatPercentage(this.getCorrectnessProbability())); } }
long finishTime = System.currentTimeMillis(); CrossPlatformExecutor.this.logger.info("Executed {} in {}.", stage, Formats.formatDuration(finishTime - startTime, true));
/** * Tries to execute the given {@link ExecutionStage}. * * @param stageActivator that should be executed * @return whether the {@link ExecutionStage} was really executed */ private void execute(StageActivator stageActivator) { final ExecutionStage stage = stageActivator.getStage(); final OptimizationContext optimizationContext = stageActivator.getOptimizationContext(); // Find parts of the stage to instrument. this.instrumentationStrategy.applyTo(stage); // Obtain an Executor for the stage. Executor executor = this.getOrCreateExecutorFor(stage); // Have the execution done. CrossPlatformExecutor.this.logger.info("Having {} execute {}:\n{}", executor, stage, stage.getPlanAsString("> ")); long startTime = System.currentTimeMillis(); executor.execute(stage, optimizationContext, this); long finishTime = System.currentTimeMillis(); CrossPlatformExecutor.this.logger.info("Executed {} in {}.", stage, Formats.formatDuration(finishTime - startTime, true)); // Remember that we have executed the stage. this.completedStages.add(stage); if (stage.isLoopHead()) { this.getOrCreateLoopContext(stage.getLoop()).scrapPreviousTransitionContext(); } }
@Override public void warmUp(Configuration configuration) { super.warmUp(configuration); // Run a most simple Spark job. this.logger.info("Running warm-up Spark job..."); long startTime = System.currentTimeMillis(); final RheemContext rheemCtx = new RheemContext(configuration); SparkCollectionSource<Integer> source = new SparkCollectionSource<>( Collections.singleton(0), DataSetType.createDefault(Integer.class) ); SparkLocalCallbackSink<Integer> sink = new SparkLocalCallbackSink<>( dq -> { }, DataSetType.createDefault(Integer.class) ); source.connectTo(0, sink, 0); final Job job = rheemCtx.createJob("Warm up", new RheemPlan(sink)); // Make sure not to have the warm-up jobs bloat the execution logs. job.getConfiguration().setProperty("rheem.core.log.enabled", "false"); job.execute(); long stopTime = System.currentTimeMillis(); this.logger.info("Spark warm-up finished in {}.", Formats.formatDuration(stopTime - startTime, true)); }
this.logger.warn("Execution of {} took suspiciously long ({}).", task, Formats.formatDuration(executionDuration));
this.logger.info( "Accumulated execution time: {} (effective: {}, overhead: {})", Formats.formatDuration(measuredExecutionMillis, true), Formats.formatDuration(effectiveExecutionMillis, true), Formats.formatDuration(measuredExecutionMillis - effectiveExecutionMillis, true) ); int i = 1;
this.logger.warn("Execution of {} took suspiciously long ({}).", task, Formats.formatDuration(executionDuration));