Skip to content
Snippets Groups Projects
Commit 10cdf7e7 authored by brinn's avatar brinn
Browse files

add: more debug log messages

SVN: 15291
parent ece3d729
No related branches found
No related tags found
No related merge requests found
......@@ -72,7 +72,7 @@ public final class DirectoryScannedStore implements IScannedStore
}
}
public StoreItem[] filterReadyToProcess(StoreItem[] items, ISimpleLogger loggerOrNull)
public StoreItem[] tryFilterReadyToProcess(StoreItem[] items, ISimpleLogger loggerOrNull)
{
StoreItem currentItem = null;
try
......
......@@ -32,6 +32,7 @@ import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import ch.systemsx.cisd.base.exceptions.InterruptedExceptionUnchecked;
import ch.systemsx.cisd.base.exceptions.TimeoutExceptionUnchecked;
import ch.systemsx.cisd.common.collections.CollectionUtils;
import ch.systemsx.cisd.common.exceptions.Status;
import ch.systemsx.cisd.common.filesystem.IDirectoryScanningHandler.HandleInstruction;
......@@ -169,8 +170,8 @@ public final class DirectoryScanningTimerTask extends TimerTask implements ITime
final IPathHandler pathHandler, final int ignoredErrorCount)
{
this(asScannedStore(sourceDirectory, fileFilter), new FaultyPathDirectoryScanningHandler(
sourceDirectory, pathHandler), PathHandlerAdapter
.asScanningHandler(sourceDirectory, pathHandler), ignoredErrorCount);
sourceDirectory, pathHandler), PathHandlerAdapter.asScanningHandler(
sourceDirectory, pathHandler), ignoredErrorCount);
}
private final static IScannedStore asScannedStore(final File directory, final FileFilter filter)
......@@ -180,7 +181,13 @@ public final class DirectoryScanningTimerTask extends TimerTask implements ITime
private final void printNotification(final Exception ex)
{
notificationLog.error("An exception has occurred. (thread still running)", ex);
if (ex instanceof TimeoutExceptionUnchecked)
{
notificationLog.error("Timeout while scanning directory: " + ex.getMessage(), ex);
} else
{
notificationLog.error("An exception has occurred. (thread still running)", ex);
}
}
private final StoreItem[] listStoreItems()
......@@ -225,32 +232,70 @@ public final class DirectoryScanningTimerTask extends TimerTask implements ITime
{
numberOfItemsProcessedInLastRound = 0;
final StoreItem[] allStoreItems = listStoreItems();
if (operationLog.isTraceEnabled())
{
operationLog.trace(String.format("Found %d store items in total.",
allStoreItems.length));
}
cleanseErrorLog(allStoreItems);
final StoreItem[] storeItems =
sourceDirectory.filterReadyToProcess(allStoreItems, notificationLogger);
if (storeItems == null)
if (operationLog.isTraceEnabled())
{
operationLog.trace(String.format(
"Found %d store items that are not in error state.",
allStoreItems.length));
}
final StoreItem[] storeItemsOrNull =
sourceDirectory.tryFilterReadyToProcess(allStoreItems, notificationLogger);
if (operationLog.isTraceEnabled())
{
operationLog.trace(String.format("Found %d store items ready to be processed.",
(storeItemsOrNull == null) ? 0 : storeItemsOrNull.length));
}
if (storeItemsOrNull == null)
{
break;
}
final int numberOfItems = storeItems.length;
final int numberOfItems = storeItemsOrNull.length;
directoryScanningHandler.beforeHandle();
if (operationLog.isTraceEnabled())
{
operationLog.trace("beforeHandle() completed.");
}
for (int i = 0; i < numberOfItems; i++)
{
final StoreItem storeItem = storeItems[i];
final StoreItem storeItem = storeItemsOrNull[i];
if (operationLog.isTraceEnabled())
{
operationLog.trace(String
.format("Looping over store item '%s'.", storeItem));
}
if (stopRun || Thread.interrupted() || storeHandler.isStopped())
{
if (operationLog.isDebugEnabled())
{
operationLog.debug(String.format(
"Scan of store '%s' has been cancelled. "
operationLog
.debug(String.format("Scan of store '%s' has been cancelled. "
+ "Following items have NOT been handled: %s.",
sourceDirectory, CollectionUtils.abbreviate(ArrayUtils
.subarray(storeItems, i + 1, numberOfItems), 10)));
sourceDirectory, CollectionUtils.abbreviate(ArrayUtils
.subarray(storeItemsOrNull, i + 1,
numberOfItems), 10)));
}
return;
}
final HandleInstruction instruction =
directoryScanningHandler.mayHandle(sourceDirectory, storeItem);
if (operationLog.isTraceEnabled())
{
if (instruction.tryGetMessage() == null)
{
operationLog.trace(String.format("Handle instruction: %s.", instruction
.getFlag()));
} else
{
operationLog.trace(String.format("Handle instruction: %s [%s].",
instruction.getFlag(), instruction.tryGetMessage()));
}
}
if (HandleInstructionFlag.PROCESS.equals(instruction.getFlag()))
{
try
......@@ -385,11 +430,11 @@ public final class DirectoryScanningTimerTask extends TimerTask implements ITime
* @returns Only those <var>items</var> which are ready to be processed right now, or
* <code>null</code>, if the filtering step produced an exception.
*/
StoreItem[] filterReadyToProcess(final StoreItem[] items, ISimpleLogger loggerOrNull);
StoreItem[] tryFilterReadyToProcess(final StoreItem[] items, ISimpleLogger loggerOrNull);
/**
* Returns <code>true</code>, if the <var>item</var> either still exists or is in an
* error state.
* Returns <code>true</code>, if the <var>item</var> either still exists or is in an error
* state.
*/
boolean existsOrError(StoreItem item);
......
......@@ -84,7 +84,7 @@ final class FileScannedStore implements IScannedStore
return items;
}
public final StoreItem[] filterReadyToProcess(final StoreItem[] items,
public final StoreItem[] tryFilterReadyToProcess(final StoreItem[] items,
ISimpleLogger loggerOrNull)
{
StoreItem currentItem = null;
......
......@@ -18,8 +18,12 @@ package ch.systemsx.cisd.datamover.filesystem;
import java.io.File;
import org.apache.log4j.Logger;
import ch.rinn.restrictions.Private;
import ch.systemsx.cisd.common.highwatermark.HostAwareFileWithHighwaterMark;
import ch.systemsx.cisd.common.logging.LogCategory;
import ch.systemsx.cisd.common.logging.LogFactory;
import ch.systemsx.cisd.datamover.filesystem.intf.AbstractFileStore;
import ch.systemsx.cisd.datamover.filesystem.intf.IFileStore;
import ch.systemsx.cisd.datamover.filesystem.intf.IFileSysOperationsFactory;
......@@ -34,6 +38,9 @@ import ch.systemsx.cisd.datamover.filesystem.store.FileStoreRemoteMounted;
*/
public final class FileStoreFactory
{
private static final Logger operationLog =
LogFactory.getLogger(LogCategory.OPERATION, FileStoreFactory.class);
private FileStoreFactory()
{
// This class can not be instantiated.
......@@ -98,16 +105,36 @@ public final class FileStoreFactory
{
if (path.tryGetHost() != null)
{
if (operationLog.isDebugEnabled())
{
operationLog.debug(String.format(
"Create %s store for remote host %s, path %s, timeout: %f s.", kind, path
.tryGetHost(), path.getFile().toString(),
FileStoreRemote.LONG_SSH_TIMEOUT_MILLIS / 1000.0));
}
return createRemoteHost(path, kind, factory, skipAccessibilityTest,
findExecutableOrNull, lastchangedExecutableOrNull);
} else
{
final long timoutMillis = checkIntervalMillis * 3;
if (isRemote)
{
if (operationLog.isDebugEnabled())
{
operationLog.debug(String.format(
"Create %s store for mounted path %s, timeout: %f s.", kind, path
.getFile().toString(), timoutMillis / 1000.0));
}
return new FileStoreRemoteMounted(path, kind, factory, skipAccessibilityTest,
checkIntervalMillis * 3);
timoutMillis);
} else
{
if (operationLog.isDebugEnabled())
{
operationLog.debug(String.format(
"Create %s store for local path %s.", kind, path
.getFile().toString()));
}
return createLocal(path, kind, factory, skipAccessibilityTest);
}
}
......
......@@ -56,9 +56,9 @@ public class FileStoreRemote extends AbstractFileStore
private static final String NO_SUCH_FILE_OR_DIRECTORY_MSG = "No such file or directory";
private static final long QUICK_SSH_TIMEOUT_MILLIS = 15 * 1000;
public static final long QUICK_SSH_TIMEOUT_MILLIS = 15 * 1000;
private static final long LONG_SSH_TIMEOUT_MILLIS = 120 * 1000;
public static final long LONG_SSH_TIMEOUT_MILLIS = 120 * 1000;
// -- bash commands -------------
......
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment