@Override public void rejectedExecution(Runnable theRunnable, ThreadPoolExecutor theExecutor) { ourLog.info("Note: Executor queue is full ({} elements), waiting for a slot to become available!", executorQueue.size()); StopWatch sw = new StopWatch(); try { executorQueue.put(theRunnable); } catch (InterruptedException theE) { throw new RejectedExecutionException("Task " + theRunnable.toString() + " rejected from " + theE.toString()); } ourLog.info("Slot become available after {}ms", sw.getMillis()); } };
private int doExpungeEverythingQuery(String theQuery) { StopWatch sw = new StopWatch(); int outcome = myEntityManager.createQuery(theQuery).executeUpdate(); if (outcome > 0) { ourLog.debug("Query affected {} rows in {}: {}", outcome, sw.toString(), theQuery); } else { ourLog.debug("Query affected {} rows in {}: {}", outcome, sw.toString(), theQuery); } return outcome; }
/** * Starts a counter for a sub-task * <p> * <b>Thread Safety Note: </b> This method is not threadsafe! Do not use subtasks in a * multithreaded environment. * </p> * * @param theTaskName Note that if theTaskName is blank or empty, no task is started */ public void startTask(String theTaskName) { endCurrentTask(); if (isNotBlank(theTaskName)) { myCurrentTask = new TaskTiming() .setTaskName(theTaskName) .setStart(now()); myTasks.add(myCurrentTask); } }
/** * Formats value in an appropriate format. See {@link #formatMillis(long)}} * for a description of the format * * @see #formatMillis(long) */ @Override public String toString() { return formatMillis(getMillis()); }
@Override public DaoMethodOutcome delete(IIdType theId, RequestDetails theRequestDetails) { List<DeleteConflict> deleteConflicts = new ArrayList<DeleteConflict>(); StopWatch w = new StopWatch(); DaoMethodOutcome retVal = delete(theId, deleteConflicts, theRequestDetails); validateDeleteConflictsEmptyOrThrowException(deleteConflicts); ourLog.debug("Processed delete on {} in {}ms", theId.getValue(), w.getMillisAndRestart()); return retVal; }
private void processDeferredConcepts() { int codeCount = 0, relCount = 0; StopWatch stopwatch = new StopWatch(); codeCount, myDeferredConcepts.size(), myConceptLinksToSaveLater.size(), stopwatch.getMillis(), stopwatch.getMillisPerOperation(codeCount)); relCount, myConceptLinksToSaveLater.size(), stopwatch.getMillis(), stopwatch.getMillisPerOperation(relCount));
private void runJob(SubscriptionTriggeringJobDetails theJobDetails) { StopWatch sw = new StopWatch(); ourLog.info("Starting pass of subscription triggering job {}", theJobDetails.getJobId()); ourLog.info("Subscription trigger job[{}] triggered {} resources in {}ms ({} res / second)", theJobDetails.getJobId(), totalSubmitted, sw.getMillis(), sw.getThroughput(totalSubmitted, TimeUnit.SECONDS));
@Override public IHttpResponse execute() throws IOException { StopWatch responseStopWatch = new StopWatch(); HttpResponse httpResponse = myClient.execute(myRequest); return new ApacheHttpResponse(httpResponse, responseStopWatch); }
StopWatch sw = new StopWatch(); AtomicInteger counter = new AtomicInteger(); StopWatch pageSw = new StopWatch(); Slice<Long> range = myTxTemplate.execute(t -> { PageRequest page = PageRequest.of(0, PASS_SIZE); Validate.notNull(range); int count = range.getNumberOfElements(); ourLog.info("Loaded {} resources for reindexing in {}", count, pageSw.toString()); }); ourLog.info("Completed pass of reindex JOB[{}] - Indexed {} resources in {} ({} / sec) - Have indexed until: {}", theJob.getId(), count, sw.toString(), sw.formatThroughput(count, TimeUnit.SECONDS), newLow); return counter.get();
final StopWatch transactionStopWatch = new StopWatch(); Map<BUNDLEENTRY, ResourceTable> retVal = doTransactionWriteOperations(theRequestDetails, theActionName, updateTime, allIds, idSubstitutions, idToPersistedOutcome, response, originalRequestOrder, entries, transactionStopWatch); transactionStopWatch.startTask("Commit writes to database"); return retVal; }); transactionStopWatch.endCurrentTask(); transactionStopWatch.startTask("Process " + getEntries.size() + " GET entries"); transactionStopWatch.endCurrentTask(); ourLog.info("Transaction timing:\n{}", transactionStopWatch.formatTaskDurations());
private <T> void doDelete(String theDescriptor, Supplier<Slice<T>> theLoader, Supplier<Integer> theCounter, JpaRepository<T, ?> theDao) { int count; ourLog.info(" * Deleting {}", theDescriptor); int totalCount = theCounter.get(); StopWatch sw = new StopWatch(); count = 0; while (true) { Slice<T> link = theLoader.get(); if (link.hasContent() == false) { break; } TransactionTemplate txTemplate = new TransactionTemplate(myTransactionManager); txTemplate.setPropagationBehavior(TransactionDefinition.PROPAGATION_REQUIRED); txTemplate.execute(t -> { theDao.deleteInBatch(link); return null; }); count += link.getNumberOfElements(); ourLog.info(" * {} {} deleted - {}/sec - ETA: {}", count, theDescriptor, sw.formatThroughput(count, TimeUnit.SECONDS), sw.getEstimatedTimeRemaining(count, totalCount)); } theDao.flush(); }
/** * @param theNumOperations Ok for this to be 0, it will be treated as 1 */ public int getMillisPerOperation(int theNumOperations) { return (int) (((double) getMillis()) / Math.max(1.0, theNumOperations)); }
String timing = " in " + theResponse.getRequestStopWatch().toString(); myLog.info("Client response: {}{}{}", message, respLocation, timing);
BUNDLEENTRY nextRespEntry = myVersionAdapter.getEntries(theResponse).get(order); theTransactionStopWatch.startTask("Bundle.entry[" + i + "]: " + verb + " " + defaultString(resourceType)); theTransactionStopWatch.endCurrentTask(); theTransactionStopWatch.startTask("Index " + theIdToPersistedOutcome.size() + " resources"); for (DaoMethodOutcome nextOutcome : theIdToPersistedOutcome.values()) { IBaseResource nextResource = nextOutcome.getResource(); theTransactionStopWatch.endCurrentTask(); theTransactionStopWatch.startTask("Flush writes to database"); theTransactionStopWatch.endCurrentTask(); if (conditionalRequestUrls.size() > 0) { theTransactionStopWatch.startTask("Check for conflicts in conditional resources"); theTransactionStopWatch.endCurrentTask();
/** * Determine the current throughput per unit of time (specified in theUnit) * assuming that theNumOperations operations have happened. * <p> * For example, if this stopwatch has 2 seconds elapsed, and this method is * called for theNumOperations=30 and TimeUnit=SECONDS, * this method will return 15 * </p> * * @see #getThroughput(int, TimeUnit) */ public String formatThroughput(int theNumOperations, TimeUnit theUnit) { double throughput = getThroughput(theNumOperations, theUnit); return new DecimalFormat("0.0").format(throughput); }
@Override public TagList getTags(IIdType theResourceId, RequestDetails theRequestDetails) { // Notify interceptors ActionRequestDetails requestDetails = new ActionRequestDetails(theRequestDetails, null, theResourceId); notifyInterceptors(RestOperationTypeEnum.GET_TAGS, requestDetails); StopWatch w = new StopWatch(); TagList retVal = super.getTags(myResourceType, theResourceId); ourLog.debug("Processed getTags on {} in {}ms", theResourceId, w.getMillisAndRestart()); return retVal; }
@Override protected void doInTransactionWithoutResult(TransactionStatus theArg0) { int maxResult = 1000; Page<TermConcept> concepts = myConceptDao.findResourcesRequiringReindexing(new PageRequest(0, maxResult)); if (concepts.hasContent() == false) { if (myChildToParentPidCache != null) { ourLog.info("Clearing parent concept cache"); myNextReindexPass = System.currentTimeMillis() + DateUtils.MILLIS_PER_MINUTE; myChildToParentPidCache = null; } return; } if (myChildToParentPidCache == null) { myChildToParentPidCache = ArrayListMultimap.create(); } ourLog.info("Indexing {} / {} concepts", concepts.getContent().size(), concepts.getTotalElements()); int count = 0; StopWatch stopwatch = new StopWatch(); for (TermConcept nextConcept : concepts) { if (isBlank(nextConcept.getParentPidsAsString())) { StringBuilder parentsBuilder = new StringBuilder(); createParentsString(parentsBuilder, nextConcept.getId()); nextConcept.setParentPids(parentsBuilder.toString()); } saveConcept(nextConcept); count++; } ourLog.info("Indexed {} / {} concepts in {}ms - Avg {}ms / resource", count, concepts.getContent().size(), stopwatch.getMillis(), stopwatch.getMillisPerOperation(count)); } });
private void runJob(SubscriptionTriggeringJobDetails theJobDetails) { StopWatch sw = new StopWatch(); ourLog.info("Starting pass of subscription triggering job {}", theJobDetails.getJobId()); ourLog.info("Subscription trigger job[{}] triggered {} resources in {}ms ({} res / second)", theJobDetails.getJobId(), totalSubmitted, sw.getMillis(), sw.getThroughput(totalSubmitted, TimeUnit.SECONDS));
@Override public IHttpResponse execute() throws IOException { StopWatch responseStopWatch = new StopWatch(); myRequestBuilder.method(getHttpVerbName(), myRequestBody); Call call = myClient.newCall(myRequestBuilder.build()); return new OkHttpRestfulResponse(call.execute(), responseStopWatch); }
StopWatch sw = new StopWatch(); AtomicInteger counter = new AtomicInteger(); StopWatch pageSw = new StopWatch(); Slice<Long> range = myTxTemplate.execute(t -> { PageRequest page = PageRequest.of(0, PASS_SIZE); Validate.notNull(range); int count = range.getNumberOfElements(); ourLog.info("Loaded {} resources for reindexing in {}", count, pageSw.toString()); }); ourLog.info("Completed pass of reindex JOB[{}] - Indexed {} resources in {} ({} / sec) - Have indexed until: {}", theJob.getId(), count, sw.toString(), sw.formatThroughput(count, TimeUnit.SECONDS), newLow); return counter.get();