/** * Mark the end of the previous action. */ public static void stop(String message) { if (!log.isDebugEnabled()) { return; } final String tn = getThreadName(); log.debug(PREFIX + tn + " -> " + tn + ": " + format(message) + "\n" + PREFIX + "deactivate " + tn); }
/** * Mark the beginning of an action */ public static void start(String message) { start(message, DEFAULT_COLOR); }
/** * Mark the beginning of an action initiated by the caller. */ public static void startFrom(final String callerThread, final String message) { startFrom(callerThread, message, DEFAULT_COLOR); }
/** * Mark the beginning of an action initiated by the caller. */ public static void startFrom(final String callerThread, final String message, final String color) { if (!log.isDebugEnabled()) { return; } final String tn = getThreadName(); log.debug(PREFIX + sanitize(callerThread) + " o--> " + tn + ": Initiate\n" + PREFIX + tn + " -> " + tn + ": " + format(message) + "\n" + PREFIX + "activate " + tn + " " + color); }
private static String format(String message) { String ret = sanitize(message).replace(", ", ",\\n"); ret = insertNewLine(ret); return ret; }
@Override public Boolean call() { SequenceTracer.startFrom(callerThread, "BulkPostcommit", "#ff410f"); if (log.isDebugEnabled()) { log.debug("Events postcommit bulk execution starting in thread: " + Thread.currentThread().getName()); continue; SequenceTracer.start("run listener " + listener.getName()); if (log.isDebugEnabled()) { log.debug("Events postcommit bulk execution start for listener: " + listener.getName()); + " in " + elapsed + "ms"); SequenceTracer.stop("listener done " + elapsed + " ms"); SequenceTracer.stop("BulkPostcommit done " + elapsed + " ms"); if (log.isDebugEnabled()) { log.debug("Events postcommit bulk execution finished in " + elapsed + "ms");
@Override public boolean awaitCompletion(String queueId, long duration, TimeUnit unit) throws InterruptedException { if (!isStarted()) { return true; } SequenceTracer.start("awaitCompletion on " + (queueId == null ? "all queues" : queueId)); long durationInMs = TimeUnit.MILLISECONDS.convert(duration, unit); long deadline = getTimestampAfter(durationInMs); int pause = (int) Math.min(durationInMs, 500L); log.debug("awaitForCompletion {} ms", durationInMs); do { if (noScheduledOrRunningWork(queueId)) { completionSynchronizer.signalCompletedWork(); SequenceTracer.stop("done"); return true; } completionSynchronizer.waitForCompletedWork(pause); } while (System.currentTimeMillis() < deadline); log.info("awaitCompletion timeout after {} ms", durationInMs); SequenceTracer.destroy("timeout after " + durationInMs + " ms"); return false; }
public EventBundleBulkRunner(List<EventListenerDescriptor> listeners, EventBundle bundle) { this.listeners = listeners; this.bundle = bundle; callerThread = SequenceTracer.getThreadName(); }
/** * Get the thread name sanitized for plantuml */ public static String getThreadName() { return sanitize(Thread.currentThread().getName()); }
void processIndexCommand(IndexingCommand cmd) { IndexRequest request; try { request = buildEsIndexingRequest(cmd); } catch (BlobNotFoundException pe) { request = null; } catch (DocumentNotFoundException e) { request = null; } catch (IllegalStateException e) { log.error("Fail to create request for indexing command: " + cmd, e); return; } if (request == null) { log.info("Cancel indexing command because target document does not exists anymore: " + cmd); return; } if (log.isDebugEnabled()) { logDebugMessageTruncated(String.format("Index request: curl -XPUT 'http://localhost:9200/%s/%s/%s' -d '%s'", getWriteIndexForRepository(cmd.getRepositoryName()), DOC_TYPE, cmd.getTargetDocumentId(), request.toString()), MAX_CURL_LINE); } try { esa.getClient().index(request); } catch (ConcurrentUpdateException e) { SequenceTracer.addNote("Ignore indexing of doc " + cmd.getTargetDocumentId()); log.info("Ignore indexing of doc " + cmd.getTargetDocumentId() + " a more recent version has already been indexed: " + e.getMessage()); } }
/** * Called when the worker failed to run successfully even after retrying. * @since 10.1 * @param exception the exception that occurred */ public void workFailed(RuntimeException exception) { EventService service = Framework.getService(EventService.class); EventContext eventContext = new EventContextImpl(null, session != null ? session.getPrincipal() : null); eventContext.setProperties(buildWorkFailureEventProps(exception)); Event event = new EventImpl(WORK_FAILED_EVENT, eventContext); event.setIsCommitEvent(true); service.fireEvent(event); if (exception != null) { String msg = "Work failed after " + getRetryCount() + " " + (getRetryCount() == 1 ? "retry" : "retries") + ", class=" + getClass() + " id=" + getId() + " category=" + getCategory() + " title=" + getTitle(); SequenceTracer.destroy("Work failure " + (completionTime - startTime) + " ms"); // all retries have been done, throw the exception throw new NuxeoException(msg, exception); } }
log.debug("Events postcommit execution starting in thread: " + Thread.currentThread().getName()); SequenceTracer.startFrom(callerThread, "Postcommit", "#ff410f"); long t0 = System.currentTimeMillis(); EventStats stats = Framework.getService(EventStats.class); log.debug("Events postcommit execution start for listener: " + listener.getName()); SequenceTracer.start("run listener " + listener.getName()); long t1 = System.currentTimeMillis(); + elapsed + "ms"); SequenceTracer.stop("listener done " + elapsed + " ms"); log.debug("Events postcommit execution finished in " + elapsed + "ms"); SequenceTracer.stop("postcommit done" + elapsed + " ms"); return Boolean.TRUE; // no error to report
SequenceTracer.start("Fire sync event " + event.getName()); desc.asEventListener().handleEvent(event); long elapsed = System.currentTimeMillis() - t0; SequenceTracer.stop("done in " + elapsed + " ms"); if (stats != null) { stats.logSyncExec(desc, elapsed); } catch (RuntimeException e) { SequenceTracer.destroy("failure"); String message = "Exception during " + desc.getName() + " sync listener execution, "; if (event.isBubbleException()) {
public EventBundleRunner(List<EventListenerDescriptor> listeners, EventBundle bundle) { this.listeners = listeners; this.bundle = bundle; callerThread = SequenceTracer.getThreadName(); }
/** * Mark the last action as failure */ public static void destroy(String message) { if (!log.isDebugEnabled()) { return; } final String tn = getThreadName(); log.debug(PREFIX + tn + " -> " + tn + ": " + format(message) + "\n" + PREFIX + "destroy " + tn); }
public AbstractWork(String id) { this.id = id; progress = PROGRESS_INDETERMINATE; schedulingTime = System.currentTimeMillis(); callerThread = SequenceTracer.getThreadName(); }
/** * Mark the beginning of an action */ public static void start(String message, String color) { if (!log.isDebugEnabled()) { return; } final String tn = getThreadName(); log.debug(PREFIX + tn + " -> " + tn + ": " + format(message) + "\n" + PREFIX + "activate " + tn + " " + color); }
/** * Mark an event. */ public static void mark(String message) { if (!log.isDebugEnabled()) { return; } final String tn = getThreadName(); log.debug(PREFIX + tn + " -> " + tn + ": " + message); }
/** * Link from source to current thread. */ public static void addRelation(String source, String message) { if (!log.isDebugEnabled()) { return; } log.debug(PREFIX + source + " --> " + getThreadName() + ": " + format(message)); }