/** Writes a detailed informational status message to the log, at INFO level */
private final void logStatusInfo() {
if (info(log)) {
try {
final int batchesInProgress =
importThreadPool.getQueueSize() + importThreadPool.getActiveCount();
final Float batchesPerSecond =
importStatus.getTargetCounterRate(
BulkImportStatus.TARGET_COUNTER_BATCHES_COMPLETE, SECONDS);
final Long estimatedCompletionTimeInNs = importStatus.getEstimatedRemainingDurationInNs();
String message = null;
if (batchesPerSecond != null && estimatedCompletionTimeInNs != null) {
message =
String.format(
"Multithreaded import in progress - %d batch%s yet to be imported. "
+ "At current rate (%.3f batch%s per second), estimated completion in %s.",
batchesInProgress,
pluralise(batchesInProgress, "es"),
batchesPerSecond,
pluralise(batchesPerSecond, "es"),
getHumanReadableDuration(estimatedCompletionTimeInNs, false));
} else {
message =
String.format(
"Multithreaded import in progress - %d batch%s yet to be imported.",
batchesInProgress, pluralise(batchesInProgress, "es"));
}
info(log, message);
} catch (final IllegalFormatException ife) {
// To help troubleshoot bugs in the String.format calls above
error(log, ife);
}
}
}
/**
* Used to submit a batch to the import thread pool. Note that this method can block (due to the
* use of a blocking queue in the thread pool).
*
* @param batch The batch to submit <i>(may be null or empty, although that will result in a
* no-op)</i>.
*/
private void submitBatch(final Batch batch) {
if (batch != null && batch.size() > 0) {
if (importStatus.inProgress() && !importStatus.isStopping()) {
importThreadPool.execute(new BatchImportJob(batch));
} else {
if (warn(log)) warn(log, "New batch submitted during shutdown - ignoring new work.");
}
}
}
private synchronized void submitCurrentBatch() throws InterruptedException {
// Implement pauses at batch boundaries only
pauser.blockIfPaused();
if (currentBatch != null && currentBatch.size() > 0) {
final Batch batch = new Batch(currentBatchNumber, currentBatch);
// Prepare for the next batch
currentBatch = null;
importStatus.incrementTargetCounter(BulkImportStatus.TARGET_COUNTER_BATCHES_SUBMITTED);
if (multiThreadedImport) {
// Submit the batch to the thread pool
submitBatch(batch);
} else {
// Import the batch directly on this thread
batchImporter.importBatch(userId, target, batch, replaceExisting, dryRun);
// Check if the multi-threading threshold has been reached
multiThreadedImport = filePhase && currentBatchNumber >= MULTITHREADING_THRESHOLD;
if (multiThreadedImport && debug(log))
debug(
log,
"Multi-threading threshold ("
+ MULTITHREADING_THRESHOLD
+ " batch"
+ pluralise(MULTITHREADING_THRESHOLD, "es")
+ ") reached - switching to multi-threaded import.");
}
}
}
/**
* @see
* org.alfresco.extension.bulkimport.BulkImportCallback#submit(org.alfresco.extension.bulkimport.source.BulkImportItem)
*/
@Override
@SuppressWarnings({"rawtypes", "unchecked"})
public synchronized void submit(final BulkImportItem item) throws InterruptedException {
// PRECONDITIONS
if (item == null) {
throw new IllegalArgumentException(
"Import source '"
+ source.getName()
+ "' has logic errors - a null import item was submitted.");
}
if (item.getVersions() == null || item.getVersions().size() <= 0) {
throw new IllegalArgumentException(
"Import source '"
+ source.getName()
+ "' has logic errors - an empty import item was submitted.");
}
// Body
if (importStatus.isStopping() || Thread.currentThread().isInterrupted())
throw new InterruptedException(
Thread.currentThread().getName() + " was interrupted. Terminating early.");
// If the weight of the new item would blow out the current batch, submit the batch as-is (i.e.
// *before* adding the newly submitted item).
// This ensures that heavy items start a new batch (and possibly end up in a batch by
// themselves).
int weight = weight(item);
if (weightOfCurrentBatch + weight > batchWeight) {
submitCurrentBatch();
}
// Create a new batch, if necessary
if (currentBatch == null) {
currentBatchNumber++;
currentBatch = new ArrayList<>(batchWeight);
weightOfCurrentBatch = 0;
}
// Finally, add the item to the current batch
currentBatch.add(item);
weightOfCurrentBatch += weight;
}
/** @see java.lang.Runnable#run() */
@Override
public void run() {
boolean inPlacePossible = false;
try {
source.init(importStatus, parameters);
inPlacePossible = source.inPlaceImportPossible();
if (info(log))
info(
log,
"Import ("
+ (inPlacePossible ? "in-place" : "streaming")
+ ") started from "
+ source.getName()
+ ".");
importStatus.importStarted(
userId, source, targetAsPath, importThreadPool, batchWeight, inPlacePossible, dryRun);
// ------------------------------------------------------------------
// Phase 1 - Folder scanning (single threaded)
// ------------------------------------------------------------------
source.scanFolders(importStatus, this);
if (debug(log))
debug(
log,
"Folder import complete in "
+ getHumanReadableDuration(importStatus.getDurationInNs())
+ ".");
// ------------------------------------------------------------------
// Phase 2 - File scanning
// ------------------------------------------------------------------
filePhase = true;
// Maximise level of concurrency, since there's no longer any risk of out-of-order batches
source.scanFiles(importStatus, this);
if (debug(log))
debug(
log,
"File scan complete in "
+ getHumanReadableDuration(importStatus.getDurationInNs())
+ ".");
importStatus.scanningComplete();
// ------------------------------------------------------------------
// Phase 3 - Wait for multi-threaded import to complete and shutdown
// ------------------------------------------------------------------
submitCurrentBatch(); // Submit whatever is left in the final (partial) batch...
awaitCompletion();
if (debug(log))
debug(log, "Import complete" + (multiThreadedImport ? ", thread pool shutdown" : "") + ".");
} catch (final Throwable t) {
Throwable rootCause = getRootCause(t);
String rootCauseClassName = rootCause.getClass().getName();
if (importStatus.isStopping()
&& (rootCause instanceof InterruptedException
|| rootCause instanceof ClosedByInterruptException
|| "com.hazelcast.core.RuntimeInterruptedException"
.equals(rootCauseClassName))) // For compatibility across 4.x *sigh*
{
// A stop import was requested
if (debug(log))
debug(log, Thread.currentThread().getName() + " was interrupted by a stop request.", t);
} else {
// An unexpected exception occurred during scanning - log it and kill the import
error(log, "Bulk import from '" + source.getName() + "' failed.", t);
importStatus.unexpectedError(t);
}
if (debug(log))
debug(log, "Forcibly shutting down import thread pool and awaiting shutdown...");
importThreadPool.shutdownNow();
try {
importThreadPool.awaitTermination(
Long.MAX_VALUE,
TimeUnit.DAYS); // Wait forever (technically merely a very long time, but whatevs...)
} catch (final InterruptedException ie) {
// Not much we can do here but log it and keep on truckin'
if (warn(log))
warn(
log,
Thread.currentThread().getName()
+ " was interrupted while awaiting shutdown of import thread pool.",
ie);
}
} finally {
// Reset the thread factory
if (importThreadPool.getThreadFactory() instanceof BulkImportThreadFactory) {
((BulkImportThreadFactory) importThreadPool.getThreadFactory()).reset();
}
// Mark the import complete
importStatus.importComplete();
// Invoke the completion handlers (if any)
if (completionHandlers != null) {
for (final BulkImportCompletionHandler handler : completionHandlers) {
try {
handler.importComplete(importStatus);
} catch (final Exception e) {
if (error(log))
error(
log, "Completion handler threw an unexpected exception. It will be ignored.", e);
}
}
}
// Always invoke the logging completion handler last
loggingBulkImportCompletionHandler.importComplete(importStatus);
}
}
