Java Code Examples for org.apache.commons.lang3.time.StopWatch#getTime()

/**
 * Monitor the elapsed time of method on controller layer, in
 * order to detect performance problems as soon as possible.
 * If elapsed time > 1 s, log it as an error. Otherwise, log it
 * as an info.
 */
@Around("controllerLayer()")
public Object monitorElapsedTime(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
    // Timing the method in controller layer
    StopWatch stopWatch = new StopWatch();
    stopWatch.start();
    Object result = proceedingJoinPoint.proceed();
    stopWatch.stop();

    // Log the elapsed time
    double elapsedTime = stopWatch.getTime() / 1000.0;
    Signature signature = proceedingJoinPoint.getSignature();
    String infoString = "[" + signature.toShortString() + "][Elapsed time: " + elapsedTime + " s]";
    if (elapsedTime > 1) {
        log.error(infoString + "[Note that it's time consuming!]");
    } else {
        log.info(infoString);
    }

    // Return the result
    return result;
}
 

public static void lang() throws NoSuchMethodException, IllegalAccessException, InvocationTargetException {
    String[] strs = new String[]{"1", "4", "2"};
    ArrayUtils.addAll(strs, "3");

    RandomUtils.nextInt(0, 10);
    RandomStringUtils.random(3);

    StopWatch stopWatch = new StopWatch();
    stopWatch.start();
    stopWatch.split();
    stopWatch.getSplitTime();
    stopWatch.suspend();
    stopWatch.resume();
    stopWatch.stop();
    stopWatch.getTime();

    long max = NumberUtils.max(new long[]{1, 5, 10}); //计算数组最大值

    MethodUtils.invokeStaticMethod(StringUtils.class, "isNotBlank", "test"); //调用静态方法
    MethodUtils.invokeMethod(StringUtils.class, "isNotBlank", "test"); //调用静态方法

    DateUtils.truncate(new Date(), Calendar.HOUR);
    DateFormatUtils.format(new Date(), "yyyyMMdd");
}
 

@Override
public Object intercept(Invocation invocation) throws Throwable {
    BoundSql boundSql = ((StatementHandler) invocation.getTarget()).getBoundSql();

    String sql = boundSql.getSql().replaceAll("\\s*\\n\\s*", " ");
    List<Object> parameters = new ArrayList<>();
    if (configuration.isShowQueryWithParameters()) {
        List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();
        Object parameterObject = boundSql.getParameterObject();
        MetaObject metaObject = MyBatisUtils.getMetaObject(parameterObject);
        if (parameterMappings.size() == 1 && !(parameterObject instanceof Map) &&
                !metaObject.hasGetter(parameterMappings.get(0).getProperty())) {
            parameters.add(parameterObject);
        } else {
            parameterMappings.forEach(pm -> parameters.add(metaObject.getValue(pm.getProperty())));
        }
    }

    StopWatch stopWatch = StopWatch.createStarted();
    Object proceed = invocation.proceed();
    long time = stopWatch.getTime();
    if (time > configuration.getSlowQueryThresholdInMillis()) {
        if (parameters.isEmpty()) {
            logger.error(String.format("[SLOW Query took %s ms] %s", time, sql));
        } else {
            logger.error(String.format("[SLOW Query took %s ms, Parameters: %s] %s ", time, parameters, sql));
        }
        BiConsumer<String, Long> slowSqlHandler = configuration.getSlowQueryHandler();
        if (slowSqlHandler != null) {
            slowSqlHandler.accept(sql, time);
        }
    } else if (configuration.isShowQuery()) {
        if (parameters.isEmpty()) {
            logger.info(String.format("[Query took %s ms] %s", time, sql));
        } else {
            logger.info(String.format("[Query took %s ms, Parameters: %s] %s ", time, parameters, sql));
        }
    }
    return proceed;
}
 

@Test
public void givenPostCourse_whenDelayInRequest_thenResponseIsDelayed() throws URISyntaxException {
    StopWatch stopWatch = new StopWatch();
    stopWatch.start();
    final ResponseEntity<Void> postResponse = restTemplate.postForEntity("http://www.baeldung.com/api/courses", null, Void.class);
    stopWatch.stop();
    long postTime = stopWatch.getTime();

    assertEquals(HttpStatus.OK, postResponse.getStatusCode());
    assertTrue(3L <= TimeUnit.MILLISECONDS.toSeconds(postTime));
}
 

private int getNextInterval(StopWatch loopTimer) {
    int nextInterval;
    long loopTime = loopTimer.getTime();
    nextInterval = Math.max(0, ((int) (repeatInterval - loopTime)));
    loopTimer.reset();
    return nextInterval;
}
 

/**
 * Stops named timer.
 * @param name name of timer to stop.
 * @return time in milliseconds since timer was started.
 */
public long stopTimer(String name) {
    StopWatch sw = getStopWatch(name);
    sw.stop();
    STOP_WATCHES.remove(name);
    return sw.getTime();
}
 

@Ignore
@Test
public void stressTestCreateUrgentEvent()
{
  // this log will be delivered to snowflake
  TelemetryService service = TelemetryService.getInstance();
  // send one http request for each event
  StopWatch sw = new StopWatch();
  sw.start();
  int rate = 1;
  int sent = 0;
  int duration = 5;
  while (sw.getTime() < duration * 1000)
  {
    int toSend = (int) (sw.getTime() / 1000) * rate - sent;
    for (int i = 0; i < toSend; i++)
    {
      TelemetryEvent log = new TelemetryEvent.LogBuilder()
          .withName("StressUrgentTestLog")
          .withValue("This is an example urgent log for stress test " + sent)
          .build();
      System.out.println("stress test: " + sent++ + " sent.");
      service.report(log);
    }
  }
  sw.stop();
}
 

@Override
public void run(GraphDatabaseService db) {
	StopWatch watch = new StopWatch();
	watch.start();
	Set<Slice> slices = generateExamples();
	watch.stop();
	long time = watch.getTime();
	System.out.println(String.format("Generate examples using %dms.", time));

	try (Transaction tx = db.beginTx()) {
		db.findNodes(Label.label(JavaCodeExtractor.METHOD)).stream().forEach(node -> {
			String belongTo = (String) node.getProperty(JavaCodeExtractor.METHOD_BELONGTO);
			String name = (String) node.getProperty(JavaCodeExtractor.METHOD_NAME);
			String params = (String) node.getProperty(JavaCodeExtractor.METHOD_PARAMS);
			params = params.replaceAll("final ", "");
			params = Stream.of(params.split(",")).map(String::trim).map(s -> s.split(" ")[0]).reduce((a, b) -> a + "," + b).orElse("");
			String signature = String.format("%s.%s(%s)", belongTo, name, params);
			List<Slice> examples = slices.stream().filter(slice -> slice.getTargetAPIs().stream().map(Object::toString).anyMatch(s -> s.equals(signature))).collect(Collectors.toList());

			Clusters clusters = new Clusters(examples);

			for (int i = 0; i < clusters.getClusters().size(); i++) {
				for (int j = 0; j < EXAMPLE_PER_CLUSTER && j < clusters.getClusters().get(i).size(); j++) {
					String example = clusters.getClusters().get(i).get(j).getSlice();
					Node exampleNode = db.createNode(Label.label(API_USAGE_EXAMPLE));
					exampleNode.setProperty(EXAMPLE_BODY, example);
					node.createRelationshipTo(exampleNode, RelationshipType.withName(HAS_EXAMPLE));
				}
			}

		});
		tx.success();
	}
}
 

@Ignore
@Test
public void perfTest() throws IOException, MkvElementVisitException, InterruptedException {
    final byte [] inputBytes = TestResourceUtil.getTestInputByteArray("output_get_media.mkv");
    int numIterations = 1000;

    StopWatch timer = new StopWatch();
    timer.start();
    for (int i = 0; i < numIterations; i++) {
        try (ByteArrayInputStream in = new ByteArrayInputStream(inputBytes);
                ByteArrayOutputStream outputStream = new ByteArrayOutputStream()) {
            OutputSegmentMerger merger =
                    OutputSegmentMerger.createDefault(outputStream);

            StreamingMkvReader mkvStreamReader =
                    StreamingMkvReader.createWithMaxContentSize(new InputStreamParserByteSource(in), 32000);
            while(mkvStreamReader.mightHaveNext()) {
                Optional<MkvElement> mkvElement = mkvStreamReader.nextIfAvailable();
                if (mkvElement.isPresent()) {
                    mkvElement.get().accept(merger);
                }
            }
        }
    }
    timer.stop();
    long totalTimeMillis = timer.getTime();
    double totalTimeSeconds = totalTimeMillis/(double )TimeUnit.SECONDS.toMillis(1);
    double mergeRate = (double )(inputBytes.length)*numIterations/(totalTimeSeconds*1024*1024);
    System.out.println("Total time "+totalTimeMillis+" ms "+" Merging rate "+mergeRate+" MB/s");
}
 

private static <T> Func1<Throwable, Single<T>> recurrsiveWithAlternateFunc(
        Func1<Quadruple<Boolean, Boolean, Duration, Integer>, Single<T>> callbackMethod, IRetryPolicy policy,
        Func1<Quadruple<Boolean, Boolean, Duration, Integer>, Single<T>> inBackoffAlternateCallbackMethod,
        ShouldRetryResult shouldRetryResult, StopWatch stopwatch, Duration minBackoffForInBackoffCallback) {
    return new Func1<Throwable, Single<T>>() {

        @Override
        public Single<T> call(Throwable t) {

            Exception e = Utils.as(t, Exception.class);
            if (e == null) {
                return Single.error(t);
            }

            stopStopWatch(stopwatch);
            logger.info("Failed inBackoffAlternateCallback with {}, proceeding with retry. Time taken: {}ms",
                    e.toString(), stopwatch.getTime());
            Duration backoffTime = shouldRetryResult.backOffTime.toMillis() > stopwatch.getTime()
                    ? Duration.ofMillis(shouldRetryResult.backOffTime.toMillis() - stopwatch.getTime())
                    : Duration.ZERO;
            return recurrsiveFunc(callbackMethod, policy, inBackoffAlternateCallbackMethod, shouldRetryResult,
                    minBackoffForInBackoffCallback)
                            .delaySubscription(Observable.timer(backoffTime.toMillis(), TimeUnit.MILLISECONDS));
        }

    };
}
 

public List<Timing<T>> getTimings() {
    final List<Timing<T>> bomToolTimings = new ArrayList<>();
    for (final T key : stopWatches.keySet()) {
        final StopWatch sw = stopWatches.get(key);
        final long ms = sw.getTime();
        final Timing timing = new Timing(key, ms);
        bomToolTimings.add(timing);
    }
    return bomToolTimings;
}
 

/**
 * Dispatches amp stage to the specified environments
 *
 * @param executionContext The environment to dispatch jobs to
 * @throws ProcessExecutionException Thrown if there is an issue during execution of an external process
 * @throws InterruptedException Thrown if user has interrupted the process during execution
 */
@Override
public ExecutionResult execute(ExecutionContext executionContext) throws ProcessExecutionException, InterruptedException {

    try {

        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        // Make a shortcut to the args
        Args args = this.getArgs();

        log.info("Starting AMP stage " + args.getIndex());

        // Make sure reads file exists
        if (args.getInputAssembly() == null || !args.getInputAssembly().exists()) {
            throw new IOException("Input file for stage: " + args.getIndex() + " does not exist: " +
                    (args.getInputAssembly() == null ? "null" : args.getInputAssembly().getAbsolutePath()));
        }

        // Make sure the inputs are reasonable
        List<Library> selectedLibs = this.validateInputs(args.getIndex(), args.getInputs(), args.getSample());

        // Create output directory
        if (!args.getOutputDir().exists()) {
            args.getOutputDir().mkdir();
        }

        // Create the configuration for this stage
        AssemblyEnhancer ampProc = this.makeStage(args, selectedLibs);

        // Set a suitable execution context
        ExecutionContext ecCopy = executionContext.copy();
        ecCopy.setContext("AMP-" + args.getIndex(), true, new File(args.getOutputDir(), "amp-" + args.getIndex() + ".log"));
        if (ecCopy.usingScheduler()) {
            ecCopy.getScheduler().getArgs().setThreads(args.getThreads());
            ecCopy.getScheduler().getArgs().setMemoryMB(args.getMemory());
        }

        // Do any setup for this process
        ampProc.setup();

        // Execute the AMP stage
        ExecutionResult result = ampProc.execute(ecCopy);

        if (!ampProc.getOutputFile().exists()) {
            throw new ProcessExecutionException(2, "AMP stage " + args.index + "\" did not produce an output file");
        }

        // Create links for outputs from this assembler to known locations
        this.getConanProcessService().createLocalSymbolicLink(ampProc.getOutputFile(), args.getOutputFile());

        stopWatch.stop();

        log.info("Finished AMP stage " + args.getIndex());

        return new DefaultExecutionResult(
                Integer.toString(args.index) + "-" + args.tool,
                0,
                result.getOutput(),
                null,
                -1,
                new ResourceUsage(result.getResourceUsage() == null ? 0 : result.getResourceUsage().getMaxMem(),
                        stopWatch.getTime() / 1000,
                        result.getResourceUsage() == null ? 0 : result.getResourceUsage().getCpuTime()));
    }
    catch (IOException | ConanParameterException e) {
        throw new ProcessExecutionException(-1, e);
    }
}
 

@Override
public ExecutionResult execute(ExecutionContext executionContext) throws ProcessExecutionException, InterruptedException {

    try {

        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        // Make a shortcut to the args
        Args args = (Args) this.getProcessArgs();

        // Gets grouped files
        List<FilePair> files = FileFinder.find(args.getInputDir(), args.isRecursive(), args.isPaired());

        log.info("Found " + files.size() + " samples to process.");

        List<ExecutionResult> jobResults = new ArrayList<>();

        // Make the output directory for this child job (delete the directory if it already exists)
        args.getOutputDir().mkdirs();

        int i =0;
        for(FilePair filePair : files) {

            JellyfishCountV11.Args jArgs = new JellyfishCountV11.Args();
            jArgs.setInputFile(args.isPaired() ?
                    filePair.getGlobedFile().getAbsolutePath() :
                    filePair.getLeft().getAbsolutePath());
            jArgs.setOutputPrefix(args.getOutputDir().getAbsolutePath() + "/" + filePair.getNamePrefix() + "_count.jf31");
            jArgs.setMerLength(31);
            jArgs.setHashSize(4000000000L);
            jArgs.setThreads(args.getThreads());
            jArgs.setBothStrands(true);
            jArgs.setLowerCount(args.getLowerCount());
            jArgs.setCounterLength(32);

            JellyfishCountV11 jProc = new JellyfishCountV11(this.conanExecutorService, jArgs);

            // Execute the assembler
            ExecutionResult result = this.conanExecutorService.executeProcess(
                    jProc,
                    args.getOutputDir(),
                    args.getJobPrefix() + "-" + i,
                    args.getThreads(),
                    args.getMemory(),
                    args.isRunParallel());

            // Add assembler id to list
            jobResults.add(result);

            i++;
        }

        // Wait for all assembly jobs to finish if they are running in parallel.
        if (executionContext.usingScheduler() && args.isRunParallel()) {
            log.debug("Jellyfish counter jobs were executed in parallel, waiting for all to complete");
            this.conanExecutorService.executeScheduledWait(
                    jobResults,
                    args.getJobPrefix() + "-group*",
                    ExitStatus.Type.COMPLETED_ANY,
                    args.getJobPrefix() + "-wait",
                    args.getOutputDir());

            jobResults.clear();
        }

        stopWatch.stop();

        TaskResult taskResult = new DefaultTaskResult("citadel-jellyswarm-count", true, jobResults, stopWatch.getTime() / 1000L);

        return new DefaultExecutionResult(
                taskResult.getTaskName(),
                0,
                new String[] {},
                null,
                -1,
                new ResourceUsage(taskResult.getMaxMemUsage(), taskResult.getActualTotalRuntime(), taskResult.getTotalExternalCputime()));
    }
    catch(IOException e) {
        throw new ProcessExecutionException(-1, e);
    }
}
 

/**
 * Executes the main method. This is public so that client distributions can test this method from their own
 * packages.
 */
@VisibleForTesting
public void execute(String[] args, Runnable exitSuccessMethod, Runnable exitFailureMethod) {
    Pair<String, Procedure<String[]>> commandEntry = getDeployCommand(args, exitFailureMethod);

    LogUtil.FileLogger logAppender = LogUtil.getLogAppender(commandEntry.getOne());

    StopWatch changeStopWatch = new StopWatch();
    changeStopWatch.start();
    LOG.info("Starting action at time [" + new Date() + "]");
    boolean success = false;

    Throwable processException = null;
    try {
        String[] argSubset = (String[]) ArrayUtils.subarray(args, 1, args.length);

        commandEntry.getTwo().value(argSubset);
        success = true;
    } catch (Throwable t) {
        processException = t;
    } finally {
        // We handle the exception and do system.exit in the finally block as we want a clean message to go out to users.
        // If we just threw the runtime exception, then that would be the last thing that appears to users, which
        // was confusing for users.

        changeStopWatch.stop();
        long runtimeSeconds = changeStopWatch.getTime() / 1000;
        String successString = success ? "successfully" : "with errors";
        LOG.info("");
        LOG.info("Action completed {} at {}, took {} seconds.", successString, new Date(), runtimeSeconds);
        LOG.info("");
        if (processException != null) {
            LOG.info("*** Exception stack trace ***", processException);
            LOG.info("");
        }
        LOG.info("Detailed Log File is available at: {}", logAppender.getLogFile());
        LOG.info("");
        LOG.info("Exiting {}!", successString);
        IOUtils.closeQuietly(logAppender);
        if (processException != null) {
            exitFailureMethod.run();
        } else {
            exitSuccessMethod.run();
        }
    }
}
 

@Override
public Iterator<FlexDocument> iterator() {
	final StopWatch timer = new StopWatch();
	Set<OWLObject> blacklist = new HashSet<>();
       blacklist.add(graph.getDataFactory().getOWLThing());
       blacklist.add(graph.getDataFactory().getOWLNothing());
	Set<OWLObject> allOWLObjects = 
	        graph.getAllOWLObjects().stream().filter(x -> !blacklist.contains(x)).collect(Collectors.toSet());
	final int totalCount = allOWLObjects.size();
	timer.start();
	final Iterator<OWLObject> objectIterator = allOWLObjects.iterator();
	
	return new Iterator<FlexDocument>() {
		
		int counter = 0;
		
		@Override
		public void remove() {
			throw new UnsupportedOperationException();
		}
		
		@Override
		public FlexDocument next() {
			OWLObject obj = objectIterator.next();
			FlexDocument doc = wring(obj, config);
			counter++;
			if( counter % 1000 == 0 ){
				long elapsed = timer.getTime();
				long eta = ((long)totalCount-counter) * (elapsed/((long)counter));
				LOG.info("Loaded: " + Integer.toString(counter) + " of " + Integer.toString(totalCount) 
						+ ", elapsed: "+DurationFormatUtils.formatDurationHMS((elapsed))
						+ ", eta: "+DurationFormatUtils.formatDurationHMS(eta));
			}
			return doc;
		}
		
		@Override
		public boolean hasNext() {
			return objectIterator.hasNext();
		}
	};
}
 

/**
 * Pauses named timer (stopping measurement), can be resumed later.
 * @param name name of timer to pause.
 * @return time in milliseconds since timer was started.
 */
public long pauseTimer(String name) {
    StopWatch sw = getStopWatch(name);
    sw.suspend();
    return sw.getTime();
}
 

@Override
public TaskResult executeSample(Mecq.Sample sample, ExecutionContext executionContext)
        throws ProcessExecutionException, InterruptedException, IOException {


    StopWatch stopWatch = new StopWatch();
    stopWatch.start();

    Args args = this.getArgs();

    List<ExecutionResult> results = new ArrayList<>();

    this.kg2FileMap.clear();
    this.mass2OptimalKmerMap.clear();

    // Execute each config
    for (Map.Entry<String, List<Library>> entry : args.getKg2inputsMap().entrySet()) {

        File kgOutputDir = new File(args.getStageDir(sample), entry.getKey());
        File kgOutputFile = new File(kgOutputDir, "kmergenie_results.log");

        kg2FileMap.put(entry.getKey(), kgOutputFile);

        // Ensure output directory for this MASS run exists
        if (!kgOutputDir.exists() && !kgOutputDir.mkdirs()) {
            throw new IOException("Couldn't create kmer genie output directory at: " + kgOutputDir.getAbsolutePath());
        }

        ExecutionResult result = this.executeKmerGenie(kgOutputDir, kgOutputFile, entry.getValue());
        result.setName("kmergenie-" + entry.getKey());
        results.add(result);
    }

    stopWatch.stop();

    return new DefaultTaskResult(sample.name + "-" + args.stage.getOutputDirName(), true, results, stopWatch.getTime() / 1000L);
}
 

@Override
public TaskResult executeSample(Mecq.Sample sample, ExecutionContext executionContext) throws ProcessExecutionException, InterruptedException, IOException {


    StopWatch stopWatch = new StopWatch();
    stopWatch.start();

    Args args = this.getArgs();


    List<ExecutionResult> results = new ArrayList<>();

    // If we have a reference run quast on it to get some stats
    if (args.getOrganism().getReference() != null && args.getOrganism().getReference().getPath() != null) {

        List<File> inputFiles = new ArrayList<>();
        inputFiles.add(args.getOrganism().getReference().getPath());
        QuastV23.Args refArgs = new QuastV23.Args();
        refArgs.setInputFiles(inputFiles);
        refArgs.setFindGenes(true);
        refArgs.setThreads(args.getThreads());
        refArgs.setEukaryote(args.getOrganism().getPloidy() > 1);
        refArgs.setOutputDir(args.getRefOutDir(sample));

        QuastV23 refQuast = new QuastV23(this.conanExecutorService, refArgs);

        results.add(this.conanExecutorService.executeProcess(refQuast, args.getRefOutDir(sample), args.jobPrefix + "-refquast", args.getThreads(), args.getMemoryMb(), args.runParallel));
    }

    stopWatch.stop();

    return new DefaultTaskResult(sample.name + "-" + args.stage.getOutputDirName(), true, results, stopWatch.getTime() / 1000L);
}
 

@Override
public TaskResult executeSample(Mecq.Sample sample, ExecutionContext executionContext)
        throws ProcessExecutionException, InterruptedException, IOException {

    Args args = this.getArgs();

    StopWatch stopWatch = new StopWatch();
    stopWatch.start();

    List<ExecutionResult> res = new ArrayList<>();

    File assembly = args.getFinaliseArgs().getScaffoldsFile(sample);

    if (!args.getAssembliesDir().exists()) {
        args.getAssembliesDir().mkdirs();
    }

     // Create link for the assembly
    this.getConanProcessService().createLocalSymbolicLink(
            assembly,
            new File(args.getAssembliesDir(), assembly.getName()));

    if (sample.libraries.size() != 1) {
        throw new IOException("Can only run KAT for 1 library per sample");
    }

    res.add(this.executeKat(sample, assembly));

    if (!args.getKatDir().exists()) {
        args.getKatDir().mkdirs();
    }


    stopWatch.stop();

    return new DefaultTaskResult(sample.name + "-" + args.stage.getOutputDirName(), true, res, stopWatch.getTime() / 1000L);
}
 

@Test
public void givenRunningTask_whenMeasuringTimeWithStopWatch_thenGetElapsedTime() throws InterruptedException {
    StopWatch watch = new StopWatch();        
    watch.start();

    simulateRunningTask();
    
    watch.stop();
    
    long timeElapsed = watch.getTime();
    
    assertEquals(true, (2000L <= timeElapsed) && (timeElapsed <= 3000L));
}