Example usage for org.springframework.util StopWatch StopWatch

List of usage examples for org.springframework.util StopWatch StopWatch

  1. HOME
  2. Java
  3. org.springframework
  4. org.springframework.util.*
  5. StopWatch
  6. StopWatch

Introduction

In this page you can find the example usage for org.springframework.util StopWatch StopWatch.

Prototype

public StopWatch(String id)

Source Link

Document

Construct a new StopWatch with the given ID.

Usage

From source file:no.abmu.user.service.UserServiceImpl.java

private Collection<PostalAddressReport> getPostalAddresses(String orgTypeName) {

    // Getting postal address data for organisationType of today.
    StopWatch stopWatchPostalAddress = new StopWatch("postalAddress");
    stopWatchPostalAddress.start("postalAddress");

    Date toDay = new Date();
    logger.info("ToDay: " + toDay);
    OrgUnitFinderSpecificationBean finderBean = new OrgUnitFinderSpecificationBean();
    finderBean.setOrganisationTypeName(orgTypeName);
    finderBean.setActiveDate(toDay);//from w  w w.  java 2s . c  o  m

    PostalAddressFinderSpecification finderSpecification = new PostalAddressFinderSpecification(finderBean);
    Collection<PostalAddressReport> postalAddresses = organisationUnitService.find(finderSpecification);

    stopWatchPostalAddress.stop();
    logger.info(
            "Getting postal addresses tok " + stopWatchPostalAddress.getTotalTimeMillis() + " milliseconds for "
                    + postalAddresses.size() + " elements " + " for organisationType " + orgTypeName);

    Comparator<OrgUnitReport> comparator = new OrgUnitReportCountyAndNameComparator();
    SortedSet<PostalAddressReport> reports = new TreeSet<PostalAddressReport>(comparator);
    reports.addAll(postalAddresses);

    return reports;
}

From source file:org.alfresco.repo.search.impl.solr.DbOrIndexSwitchingQueryLanguage.java

public ResultSet executeQuery(SearchParameters searchParameters, ADMLuceneSearcherImpl admLuceneSearcher) {
    QueryConsistency consistency = searchParameters.getQueryConsistency();
    if (consistency == QueryConsistency.DEFAULT) {
        consistency = queryConsistency;/*from   ww w.j  a v  a  2  s . c o  m*/
    }

    switch (consistency) {
    case EVENTUAL:
        if (indexQueryLanguage != null) {
            if (logger.isDebugEnabled()) {
                logger.debug("Using SOLR query: " + dbQueryLanguage.getName() + " for " + searchParameters);
            }
            StopWatch stopWatch = new StopWatch("index only");
            stopWatch.start();
            ResultSet results = indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
            stopWatch.stop();
            if (logger.isDebugEnabled()) {
                logger.debug("SOLR returned " + results.length() + " results in "
                        + stopWatch.getLastTaskTimeMillis() + "ms");
            }
            return results;
        } else {
            throw new QueryModelException("No query language available");
        }
    case TRANSACTIONAL:
        if (dbQueryLanguage != null) {
            if (logger.isDebugEnabled()) {
                logger.debug("Trying db query for " + dbQueryLanguage.getName() + " for " + searchParameters);
            }
            StopWatch stopWatch = new StopWatch("database only");
            stopWatch.start();
            ResultSet results = dbQueryLanguage.executeQuery(flattenDBQuery(searchParameters),
                    admLuceneSearcher);
            stopWatch.stop();
            if (logger.isDebugEnabled()) {
                logger.debug("DB returned " + results.length() + " results in "
                        + stopWatch.getLastTaskTimeMillis() + "ms");
            }
            return results;
        } else {
            throw new QueryModelException("No query language available");
        }
    case HYBRID:
        if (!hybridEnabled) {
            throw new DisabledFeatureException("Hybrid query is disabled.");
        }
        return executeHybridQuery(searchParameters, admLuceneSearcher);
    case DEFAULT:
    case TRANSACTIONAL_IF_POSSIBLE:
    default:
        StopWatch stopWatch = new StopWatch("DB if possible");
        if (dbQueryLanguage != null) {
            try {
                if (logger.isDebugEnabled()) {
                    logger.debug(
                            "Trying db query for " + dbQueryLanguage.getName() + " for " + searchParameters);
                }
                stopWatch.start();
                ResultSet results = dbQueryLanguage.executeQuery(flattenDBQuery(searchParameters),
                        admLuceneSearcher);
                stopWatch.stop();
                if (logger.isDebugEnabled()) {
                    logger.debug("DB returned " + results.length() + " results in "
                            + stopWatch.getLastTaskTimeMillis() + "ms");
                }
                return results;
            } catch (QueryModelException qme) {
                if (stopWatch.isRunning()) {
                    stopWatch.stop();
                }
                // MNT-10323: Logging configuration on JBoss leads to clogging of the log with a lot of these errors because of INFO level when WQS module is installed
                if (logger.isDebugEnabled()) {
                    logger.debug(
                            "DB query failed for " + dbQueryLanguage.getName() + " for " + searchParameters,
                            qme);
                }

                if (indexQueryLanguage != null) {
                    if (logger.isDebugEnabled()) {
                        logger.debug(
                                "Using SOLR query: " + dbQueryLanguage.getName() + " for " + searchParameters);
                    }
                    stopWatch.start();
                    ResultSet results = indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
                    stopWatch.stop();
                    if (logger.isDebugEnabled()) {
                        logger.debug("SOLR returned " + results.length() + " results in "
                                + stopWatch.getLastTaskTimeMillis() + "ms");
                    }
                    return results;
                }
            }
        } else {
            if (indexQueryLanguage != null) {
                if (logger.isDebugEnabled()) {
                    logger.debug("(No DB QL) Using SOLR query: " + "dbQueryLanguage==null" + " for "
                            + searchParameters);
                }
                stopWatch.start();
                ResultSet results = indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
                stopWatch.stop();
                if (logger.isDebugEnabled()) {
                    logger.debug("SOLR returned " + results.length() + " results in "
                            + stopWatch.getLastTaskTimeMillis() + "ms");
                }
                return results;
            }
        }
        throw new QueryModelException("No query language available");
    }

}

From source file:org.alfresco.repo.search.impl.solr.DbOrIndexSwitchingQueryLanguage.java

private ResultSet executeHybridQuery(SearchParameters searchParameters,
        ADMLuceneSearcherImpl admLuceneSearcher) {
    if (indexQueryLanguage == null || dbQueryLanguage == null) {
        throw new QueryModelException("Both index and DB query language required for hybrid search [index="
                + indexQueryLanguage + ", DB=" + dbQueryLanguage + "]");
    }/* w w w.jav a2 s  .  co  m*/

    StopWatch stopWatch = new StopWatch("hybrid search");
    if (logger.isDebugEnabled()) {
        logger.debug(
                "Hybrid search, using SOLR query: " + dbQueryLanguage.getName() + " for " + searchParameters);
    }
    stopWatch.start("index query");
    ResultSet indexResults = indexQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
    stopWatch.stop();
    if (logger.isDebugEnabled()) {
        logger.debug("SOLR query returned " + indexResults.length() + " results in "
                + stopWatch.getLastTaskTimeMillis() + "ms");
    }
    // TODO: if the results are up-to-date, then nothing more to do - return the results.

    if (!(indexResults instanceof SolrJSONResultSet)) {
        if (logger.isWarnEnabled()) {
            logger.warn("Hybrid search can only use database when SOLR is also in use. "
                    + "Skipping DB search, returning results from index.");
        }
        return indexResults;
    }

    long lastTxId = ((SolrJSONResultSet) indexResults).getLastIndexedTxId();
    searchParameters.setSinceTxId(lastTxId);
    if (logger.isDebugEnabled()) {
        logger.debug(
                "Hybrid search, using DB query: " + dbQueryLanguage.getName() + " for " + searchParameters);
    }
    stopWatch.start("database query");
    ResultSet dbResults = dbQueryLanguage.executeQuery(searchParameters, admLuceneSearcher);
    stopWatch.stop();
    if (logger.isDebugEnabled()) {
        logger.debug("DB query returned " + dbResults.length() + " results in "
                + stopWatch.getLastTaskTimeMillis() + "ms");
    }
    // Merge result sets
    List<ChildAssociationRef> childAssocs = new ArrayList<>();
    NodeParameters nodeParameters = new NodeParameters();
    nodeParameters.setFromTxnId(lastTxId + 1);
    // TODO: setToTxnId(null) when SolrDAO behaviour is fixed.
    nodeParameters.setToTxnId(Long.MAX_VALUE);
    stopWatch.start("get changed nodes");
    List<Node> changedNodeList = solrDao.getNodes(nodeParameters, null);
    stopWatch.stop();
    if (logger.isDebugEnabled()) {
        logger.debug("Nodes changed since last indexed transaction (ID " + lastTxId + ") = "
                + changedNodeList.size() + " (took " + stopWatch.getLastTaskTimeMillis() + "ms)");
    }
    stopWatch.start("merge result sets");
    Set<NodeRef> nodeRefs = new HashSet<>(changedNodeList.size());
    for (Node n : changedNodeList) {
        nodeRefs.add(n.getNodeRef());
    }
    // Only use the SOLR results for nodes that haven't changed since indexing.
    for (ChildAssociationRef car : indexResults.getChildAssocRefs()) {
        if (!nodeRefs.contains(car.getChildRef())) {
            childAssocs.add(car);
        }
    }
    // Merge in all the database results.
    childAssocs.addAll(dbResults.getChildAssocRefs());

    ResultSet results = new ChildAssocRefResultSet(nodeService, childAssocs);
    stopWatch.stop(); // merge result sets
    if (logger.isDebugEnabled()) {
        String stats = String.format("SOLR=%d, DB=%d, total=%d", indexResults.length(), dbResults.length(),
                results.length());
        logger.debug("Hybrid search returning combined results with counts: " + stats);
        logger.debug(stopWatch.prettyPrint());
    }
    return results;
}

From source file:org.hyperic.hq.monitor.aop.aspects.PerformanceMonitor.java

/**
 * We could bind the @Transactional annotation to the context but there's no
 * way to know if the method or the type is annotated, causing a false
 * negative./*from   w w w . j  a  va2  s .  com*/
 * @see org.hyperic.hq.monitor.aop.MonitorArchitecture
 * @param pjp
 */
@Around("org.hyperic.hq.monitor.aop.MonitorArchitecture.serviceLayerOperationDuration()")
public Object monitorServiceMethod(ProceedingJoinPoint pjp) throws Throwable {

    Object invocation = null;

    final StopWatch timer = new StopWatch(pjp.getSignature() + Thread.currentThread().getName());

    try {
        timer.start();
        invocation = pjp.proceed();
    } finally {
        timer.stop();
    }

    long duration = timer.getTotalTimeMillis();

    if (duration > maximumDuration) {
        logger.warn(new StringBuilder(warningMessage).append(pjp.getSignature()).append(" executed in ")
                .append(timer.getTotalTimeMillis()).append(":ms").toString());
    }

    return invocation;
}

From source file:org.jahia.bin.ErrorFileDumperTest.java

@Test
public void testHighLoadDeactivation() throws InterruptedException {

    logger.info("Starting testHighLoadDeactivation test...");

    RequestLoadAverage.RequestCountProvider requestCountProvider = new RequestLoadAverage.RequestCountProvider() {
        public long getRequestCount() {
            return 100;
        }/*from w w  w.j  a  v  a2  s . c  o  m*/
    };

    RequestLoadAverage requestLoadAverage = new RequestLoadAverage("requestLoadAverage", requestCountProvider);
    requestLoadAverage.start();
    logger.info("Waiting for load average to reach 10...");
    while (requestLoadAverage.getOneMinuteLoad() < 10.0) {
        Thread.sleep(500);
    }

    StopWatch stopWatch = new StopWatch("testHighLoadDeactivation");
    stopWatch.start(Thread.currentThread().getName() + " generating error dumps");

    int fileCountBeforeTest = 0;
    if (todaysDirectory.exists()) {
        File[] files = todaysDirectory.listFiles();
        fileCountBeforeTest = (files == null ? 0 : files.length);
    }

    ErrorFileDumper.setHighLoadBoundary(10.0);
    ErrorFileDumper.start();

    generateExceptions();

    stopWatch.stop();
    long totalTime = stopWatch.getTotalTimeMillis();
    double averageTime = ((double) totalTime) / ((double) LOOP_COUNT);
    logger.info("Milliseconds per exception = " + averageTime);
    logger.info(stopWatch.prettyPrint());

    ErrorFileDumper.shutdown(10000L);

    RequestLoadAverage.getInstance().stop();

    int fileCountAfterTest = 0;
    if (todaysDirectory.exists()) {
        File[] files = todaysDirectory.listFiles();
        fileCountAfterTest = (files == null ? 0 : files.length);
    }

    Assert.assertEquals("File count should stay the same because high load deactivates file dumping !",
            fileCountBeforeTest, fileCountAfterTest);

    requestLoadAverage = new RequestLoadAverage("requestLoadAverage");
}

From source file:org.jahia.bin.ErrorFileDumperTest.java

@Test
public void testDumperInSequence() throws InterruptedException {

    logger.info("Starting testDumperInSequence test...");

    StopWatch stopWatch = new StopWatch("testDumperInSequence");
    stopWatch.start(Thread.currentThread().getName() + " generating error dumps");

    ErrorFileDumper.start();//from   ww w  .j av a2s .  c  om

    generateExceptions();

    stopWatch.stop();
    long totalTime = stopWatch.getTotalTimeMillis();
    double averageTime = ((double) totalTime) / ((double) LOOP_COUNT);
    logger.info("Milliseconds per exception = " + averageTime);
    logger.info(stopWatch.prettyPrint());

    ErrorFileDumper.shutdown(10000L);

    Assert.assertTrue("Error dump directory does not exist !", todaysDirectory.exists());
    Assert.assertTrue("Error dump directory should have error files in it !",
            todaysDirectory.listFiles().length > 0);
}

From source file:org.jahia.bin.ErrorFileDumperTest.java

@Test
public void testDumpErrorsToFilesSetting() throws InterruptedException {
    logger.info("Starting testDumpErrorsToFilesSetting test...");

    StopWatch stopWatch = new StopWatch("testDumpErrorsToFilesSetting");
    stopWatch.start(Thread.currentThread().getName() + " generating error dumps");

    ErrorFileDumper.start();//from  w  w  w .  ja  v a 2 s.  c om
    ErrorFileDumper.setFileDumpActivated(false);

    generateExceptions();

    stopWatch.stop();
    long totalTime = stopWatch.getTotalTimeMillis();
    double averageTime = ((double) totalTime) / ((double) LOOP_COUNT);
    logger.info("Milliseconds per exception = " + averageTime);
    logger.info(stopWatch.prettyPrint());

    ErrorFileDumper.shutdown(10000L);

    SettingsBean.getInstance().setDumpErrorsToFiles(true);
    Assert.assertFalse("Error dump directory should not exist !", todaysDirectory.exists());
}

From source file:org.jahia.bin.ErrorFileDumperTest.java

@Test
public void testDumperInParallel() throws IOException, InterruptedException {

    logger.info("Starting testDumperInParallel test...");

    StopWatch stopWatch = new StopWatch("testDumperInParallel");
    stopWatch.start(Thread.currentThread().getName() + " generating error dumps");

    ErrorFileDumper.start();//from ww  w . j a v  a  2  s .c o  m

    threadSet.clear();

    for (int i = 0; i < THREAD_COUNT; i++) {
        Thread newThread = new Thread(new Runnable() {

            public void run() {
                generateExceptions();
            }
        }, "ErrorFileDumperTestThread" + i);
        threadSet.add(newThread);
        newThread.start();
    }

    logger.info("Waiting for dumps to be processed...");

    for (Thread curThread : threadSet) {
        curThread.join();
    }

    ErrorFileDumper.shutdown(10000L);

    stopWatch.stop();
    long totalTime = stopWatch.getTotalTimeMillis();
    double averageTime = ((double) totalTime) / ((double) LOOP_COUNT);
    logger.info("Milliseconds per exception = " + averageTime);
    logger.info(stopWatch.prettyPrint());

    Assert.assertTrue("Error dump directory does not exist !", todaysDirectory.exists());
    Assert.assertTrue("Error dump directory should have error files in it !",
            todaysDirectory.listFiles().length > 0);
}

From source file:org.jahia.bin.ErrorFileDumperTest.java

@Test
public void testOutputSystemInfoAllInParallel() throws InterruptedException {

    logger.info("Starting testOutputSystemInfoAllInParallel test...");

    StopWatch stopWatch = new StopWatch("testDumperInParallel");
    stopWatch.start(Thread.currentThread().getName() + " generating error dumps");

    ErrorFileDumper.start();// w w  w .  ja v  a2  s . c  o  m

    threadSet.clear();
    final int[] dumpLengths = new int[(int) THREAD_COUNT];

    for (int i = 0; i < THREAD_COUNT; i++) {
        final int threadCounter = i;
        Thread newThread = new Thread(new Runnable() {

            public void run() {
                // this is the call made in errors.jsp file.
                StringWriter stringWriter = new StringWriter();
                ErrorFileDumper.outputSystemInfo(new PrintWriter(stringWriter));
                dumpLengths[threadCounter] = stringWriter.toString().length();
                stringWriter = null;
            }
        }, "ErrorFileDumperTestThread" + i);
        threadSet.add(newThread);
        newThread.start();
    }

    logger.info("Waiting for dumps to be processed...");

    for (Thread curThread : threadSet) {
        curThread.join();
    }

    ErrorFileDumper.shutdown(10000L);

    stopWatch.stop();
    long totalTime = stopWatch.getTotalTimeMillis();
    double averageTime = ((double) totalTime) / ((double) LOOP_COUNT);
    logger.info("Milliseconds per exception = " + averageTime);
    logger.info(stopWatch.prettyPrint());
    for (int dumpLength : dumpLengths) {
        Assert.assertTrue("System info dump is empty", dumpLength > 0);
    }
}

From source file:org.jahia.tools.jvm.ThreadMonitorTestIT.java

private void runParallelTest(String testName, Runnable runnable) throws InterruptedException {

    StopWatch stopWatch = new StopWatch(testName);
    stopWatch.start(Thread.currentThread().getName() + " dumping thread info");

    threadSet.clear();//from   ww  w .j  av  a  2  s  .c  o m
    ThreadMonitor.getInstance().setActivated(true);
    ThreadMonitor.getInstance().setDebugLogging(enabledDebugLogging);
    ThreadMonitor.getInstance().setMinimalIntervalBetweenDumps(minimalIntervalBetweenDumps);

    for (int i = 0; i < THREAD_COUNT; i++) {
        Thread newThread = new Thread(runnable, testName + i);
        threadSet.add(newThread);
        Thread.yield();
        Thread.sleep(50);
        newThread.start();
    }

    logger.info("Waiting for test completion...");

    Thread.yield();
    while (ThreadMonitor.getInstance().isDumping()) {
        Thread.sleep(100);
    }

    for (Thread curThread : threadSet) {
        curThread.join();
    }

    ThreadMonitor.shutdownInstance();

    stopWatch.stop();
    logger.info(stopWatch.prettyPrint());

    Thread.sleep(minimalIntervalBetweenDumps * 2);
}