Repository: asterixdb Updated Branches: refs/heads/master d46165542 -> 9473e0327
[NO ISSUE][RT] Add more startup debug logs - user model changes: no - storage format changes: no - interface changes: no details: - Add more logs during startup sequence. Change-Id: I25e5c6423f3160c4becbfe682edccc49613e371c Reviewed-on: https://asterix-gerrit.ics.uci.edu/2084 Tested-by: Jenkins <[email protected]> Contrib: Jenkins <[email protected]> Integration-Tests: Jenkins <[email protected]> Reviewed-by: Ian Maxon <[email protected]> Project: http://git-wip-us.apache.org/repos/asf/asterixdb/repo Commit: http://git-wip-us.apache.org/repos/asf/asterixdb/commit/9473e032 Tree: http://git-wip-us.apache.org/repos/asf/asterixdb/tree/9473e032 Diff: http://git-wip-us.apache.org/repos/asf/asterixdb/diff/9473e032 Branch: refs/heads/master Commit: 9473e03276cace7484e4ab824da21a7368029f97 Parents: d461655 Author: Abdullah Alamoudi <[email protected]> Authored: Thu Oct 19 12:21:42 2017 -0700 Committer: abdullah alamoudi <[email protected]> Committed: Fri Oct 20 14:46:19 2017 -0700 ---------------------------------------------------------------------- .../asterix/app/nc/NCAppRuntimeContext.java | 5 +- .../asterix/app/nc/TransactionSubsystem.java | 7 ++- .../app/nc/task/BindMetadataNodeTask.java | 7 ++- .../asterix/app/nc/task/CheckpointTask.java | 7 ++- .../app/nc/task/ExternalLibrarySetupTask.java | 7 ++- .../asterix/app/nc/task/LocalRecoveryTask.java | 9 +++- .../app/nc/task/MetadataBootstrapTask.java | 7 ++- .../asterix/app/nc/task/RemoteRecoveryTask.java | 7 ++- .../app/nc/task/ReportMaxResourceIdTask.java | 5 ++ .../asterix/app/nc/task/StartFailbackTask.java | 7 ++- .../nc/task/StartLifecycleComponentsTask.java | 7 ++- .../nc/task/StartReplicationServiceTask.java | 7 ++- .../message/StartupTaskResponseMessage.java | 7 +++ .../transactions/CheckpointProperties.java | 7 +++ .../recovery/AbstractCheckpointManager.java | 56 +++++++++++++++++--- 15 files changed, 132 insertions(+), 20 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/NCAppRuntimeContext.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/NCAppRuntimeContext.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/NCAppRuntimeContext.java index 3e0f2c6..5370c03 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/NCAppRuntimeContext.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/NCAppRuntimeContext.java @@ -187,11 +187,14 @@ public class NCAppRuntimeContext implements INcApplicationContext { IAppRuntimeContextProvider asterixAppRuntimeContextProvider = new AppRuntimeContextProviderForRecovery(this); txnSubsystem = new TransactionSubsystem(getServiceContext(), getServiceContext().getNodeId(), asterixAppRuntimeContextProvider, txnProperties); - IRecoveryManager recoveryMgr = txnSubsystem.getRecoveryManager(); SystemState systemState = recoveryMgr.getSystemState(); if (initialRun || systemState == SystemState.PERMANENT_DATA_LOSS) { //delete any storage data before the resource factory is initialized + if (LOGGER.isLoggable(Level.WARNING)) { + LOGGER.log(Level.WARNING, + "Deleting the storage dir. initialRun = " + initialRun + ", systemState = " + systemState); + } localResourceRepository.deleteStorageData(true); } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/TransactionSubsystem.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/TransactionSubsystem.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/TransactionSubsystem.java index 1e920e7..4752481 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/TransactionSubsystem.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/TransactionSubsystem.java @@ -19,6 +19,7 @@ package org.apache.asterix.app.nc; import java.util.concurrent.Callable; +import java.util.logging.Level; import java.util.logging.Logger; import org.apache.asterix.common.config.ReplicationProperties; @@ -47,6 +48,7 @@ import org.apache.hyracks.api.application.INCServiceContext; * Users of transaction sub-systems must obtain them from the provider. */ public class TransactionSubsystem implements ITransactionSubsystem { + private static final Logger LOGGER = Logger.getLogger(TransactionSubsystem.class.getName()); private final String id; private final ILogManager logManager; private final ILockManager lockManager; @@ -72,8 +74,10 @@ public class TransactionSubsystem implements ITransactionSubsystem { asterixAppRuntimeContextProvider.getAppContext().getReplicationProperties(); IReplicationStrategy replicationStrategy = repProperties.getReplicationStrategy(); final boolean replicationEnabled = repProperties.isParticipant(id); - final CheckpointProperties checkpointProperties = new CheckpointProperties(txnProperties, id); + if (LOGGER.isLoggable(Level.INFO)) { + LOGGER.log(Level.INFO, "Checkpoint Properties: " + checkpointProperties); + } checkpointManager = CheckpointManagerFactory.create(this, checkpointProperties, replicationEnabled); final Checkpoint latestCheckpoint = checkpointManager.getLatest(); if (latestCheckpoint != null && latestCheckpoint.getStorageVersion() != StorageConstants.VERSION) { @@ -88,7 +92,6 @@ public class TransactionSubsystem implements ITransactionSubsystem { this.logManager = new LogManager(this); } this.recoveryManager = new RecoveryManager(this, serviceCtx); - if (this.txnProperties.isCommitProfilerEnabled()) { ecp = new EntityCommitProfiler(this, this.txnProperties.getCommitProfilerReportInterval()); getAsterixAppRuntimeContextProvider().getThreadExecutor().submit(ecp); http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/BindMetadataNodeTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/BindMetadataNodeTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/BindMetadataNodeTask.java index 424e66c..49a84e1 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/BindMetadataNodeTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/BindMetadataNodeTask.java @@ -18,8 +18,8 @@ */ package org.apache.asterix.app.nc.task; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -45,4 +45,9 @@ public class BindMetadataNodeTask implements INCLifecycleTask { throw HyracksDataException.create(e); } } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\", \"export-stub\" : " + exportStub + " }"; + } } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/CheckpointTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/CheckpointTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/CheckpointTask.java index b7701d2..02c377a 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/CheckpointTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/CheckpointTask.java @@ -18,8 +18,8 @@ */ package org.apache.asterix.app.nc.task; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.transactions.ICheckpointManager; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -34,4 +34,9 @@ public class CheckpointTask implements INCLifecycleTask { ICheckpointManager checkpointMgr = appContext.getTransactionSubsystem().getCheckpointManager(); checkpointMgr.doSharpCheckpoint(); } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\" }"; + } } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ExternalLibrarySetupTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ExternalLibrarySetupTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ExternalLibrarySetupTask.java index 9506690..4e330c6 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ExternalLibrarySetupTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ExternalLibrarySetupTask.java @@ -19,8 +19,8 @@ package org.apache.asterix.app.nc.task; import org.apache.asterix.app.external.ExternalLibraryUtils; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -42,4 +42,9 @@ public class ExternalLibrarySetupTask implements INCLifecycleTask { throw HyracksDataException.create(e); } } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\", \"metadata-node\" : " + metadataNode + " }"; + } } \ No newline at end of file http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/LocalRecoveryTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/LocalRecoveryTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/LocalRecoveryTask.java index d52d15e..eb19ad6 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/LocalRecoveryTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/LocalRecoveryTask.java @@ -19,10 +19,11 @@ package org.apache.asterix.app.nc.task; import java.io.IOException; +import java.util.Arrays; import java.util.Set; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.exceptions.ACIDException; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -45,4 +46,10 @@ public class LocalRecoveryTask implements INCLifecycleTask { throw HyracksDataException.create(e); } } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\", \"partitions\" : " + + Arrays.toString(partitions.toArray()) + " }"; + } } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/MetadataBootstrapTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/MetadataBootstrapTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/MetadataBootstrapTask.java index 6415416..784f3b0 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/MetadataBootstrapTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/MetadataBootstrapTask.java @@ -18,8 +18,8 @@ */ package org.apache.asterix.app.nc.task; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.transactions.IRecoveryManager.SystemState; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -38,4 +38,9 @@ public class MetadataBootstrapTask implements INCLifecycleTask { throw HyracksDataException.create(e); } } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\" }"; + } } \ No newline at end of file http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/RemoteRecoveryTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/RemoteRecoveryTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/RemoteRecoveryTask.java index f74a986..d330684 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/RemoteRecoveryTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/RemoteRecoveryTask.java @@ -22,8 +22,8 @@ import java.io.IOException; import java.util.Map; import java.util.Set; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -49,4 +49,9 @@ public class RemoteRecoveryTask implements INCLifecycleTask { private void readObject(java.io.ObjectInputStream in) throws IOException, ClassNotFoundException { in.defaultReadObject(); } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\", \"recovery-plan\" : " + recoveryPlan + " }"; + } } \ No newline at end of file http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ReportMaxResourceIdTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ReportMaxResourceIdTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ReportMaxResourceIdTask.java index 7c30a29..22d3cde 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ReportMaxResourceIdTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/ReportMaxResourceIdTask.java @@ -32,4 +32,9 @@ public class ReportMaxResourceIdTask implements INCLifecycleTask { public void perform(IControllerService cs) throws HyracksDataException { ReportMaxResourceIdMessage.send((NodeControllerService) cs); } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\" }"; + } } \ No newline at end of file http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartFailbackTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartFailbackTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartFailbackTask.java index 8696d23..ecd93a3 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartFailbackTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartFailbackTask.java @@ -18,8 +18,8 @@ */ package org.apache.asterix.app.nc.task; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -32,4 +32,9 @@ public class StartFailbackTask implements INCLifecycleTask { INcApplicationContext appContext = (INcApplicationContext) cs.getApplicationContext(); appContext.getRemoteRecoveryManager().startFailbackProcess(); } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\" }"; + } } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartLifecycleComponentsTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartLifecycleComponentsTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartLifecycleComponentsTask.java index 799581b..87d3414 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartLifecycleComponentsTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartLifecycleComponentsTask.java @@ -23,8 +23,8 @@ import java.util.Map; import java.util.logging.Level; import java.util.logging.Logger; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.config.MetadataProperties; import org.apache.asterix.hyracks.bootstrap.AsterixStateDumpHandler; import org.apache.hyracks.api.exceptions.HyracksDataException; @@ -61,4 +61,9 @@ public class StartLifecycleComponentsTask implements INCLifecycleTask { serviceCtx.setStateDumpHandler(new AsterixStateDumpHandler(serviceCtx.getNodeId(), lccm.getDumpPath(), lccm)); lccm.startAll(); } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\" }"; + } } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartReplicationServiceTask.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartReplicationServiceTask.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartReplicationServiceTask.java index 60d5c29..253f121 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartReplicationServiceTask.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/nc/task/StartReplicationServiceTask.java @@ -18,8 +18,8 @@ */ package org.apache.asterix.app.nc.task; -import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.api.INCLifecycleTask; +import org.apache.asterix.common.api.INcApplicationContext; import org.apache.asterix.common.replication.IReplicationManager; import org.apache.hyracks.api.exceptions.HyracksDataException; import org.apache.hyracks.api.service.IControllerService; @@ -43,4 +43,9 @@ public class StartReplicationServiceTask implements INCLifecycleTask { throw HyracksDataException.create(e); } } + + @Override + public String toString() { + return "{ \"class\" : \"" + getClass().getSimpleName() + "\" }"; + } } \ No newline at end of file http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/replication/message/StartupTaskResponseMessage.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/replication/message/StartupTaskResponseMessage.java b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/replication/message/StartupTaskResponseMessage.java index aaf8918..b941343 100644 --- a/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/replication/message/StartupTaskResponseMessage.java +++ b/asterixdb/asterix-app/src/main/java/org/apache/asterix/app/replication/message/StartupTaskResponseMessage.java @@ -53,9 +53,16 @@ public class StartupTaskResponseMessage implements INCLifecycleMessage, INcAddre Throwable exception = null; try { for (INCLifecycleTask task : tasks) { + if (LOGGER.isLoggable(Level.INFO)) { + LOGGER.log(Level.INFO, "Starting startup task: " + task); + } task.perform(cs); + if (LOGGER.isLoggable(Level.INFO)) { + LOGGER.log(Level.INFO, "Completed startup task: " + task); + } } } catch (Throwable e) { //NOSONAR all startup failures should be reported to CC + LOGGER.log(Level.SEVERE, "Failed during startup task", e); success = false; exception = e; } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-common/src/main/java/org/apache/asterix/common/transactions/CheckpointProperties.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-common/src/main/java/org/apache/asterix/common/transactions/CheckpointProperties.java b/asterixdb/asterix-common/src/main/java/org/apache/asterix/common/transactions/CheckpointProperties.java index b8af3a6..72f987a 100644 --- a/asterixdb/asterix-common/src/main/java/org/apache/asterix/common/transactions/CheckpointProperties.java +++ b/asterixdb/asterix-common/src/main/java/org/apache/asterix/common/transactions/CheckpointProperties.java @@ -50,4 +50,11 @@ public class CheckpointProperties { public String getCheckpointDirPath() { return checkpointDirPath; } + + @Override + public String toString() { + return "{\"class\" : \"" + getClass().getSimpleName() + "\", \"checkpoint-dir-path\" : \"" + checkpointDirPath + + "\", \"lsn-threshold\" : " + lsnThreshold + ", \"poll-frequency\" : " + pollFrequency + + ", \"history-to-keep\" : " + historyToKeep + " }"; + } } http://git-wip-us.apache.org/repos/asf/asterixdb/blob/9473e032/asterixdb/asterix-transactions/src/main/java/org/apache/asterix/transaction/management/service/recovery/AbstractCheckpointManager.java ---------------------------------------------------------------------- diff --git a/asterixdb/asterix-transactions/src/main/java/org/apache/asterix/transaction/management/service/recovery/AbstractCheckpointManager.java b/asterixdb/asterix-transactions/src/main/java/org/apache/asterix/transaction/management/service/recovery/AbstractCheckpointManager.java index 2a075f1..36a91dc 100644 --- a/asterixdb/asterix-transactions/src/main/java/org/apache/asterix/transaction/management/service/recovery/AbstractCheckpointManager.java +++ b/asterixdb/asterix-transactions/src/main/java/org/apache/asterix/transaction/management/service/recovery/AbstractCheckpointManager.java @@ -65,12 +65,18 @@ public abstract class AbstractCheckpointManager implements ICheckpointManager { public AbstractCheckpointManager(ITransactionSubsystem txnSubsystem, CheckpointProperties checkpointProperties) { this.txnSubsystem = txnSubsystem; String checkpointDirPath = checkpointProperties.getCheckpointDirPath(); + if (LOGGER.isLoggable(Level.INFO)) { + LOGGER.log(Level.INFO, "Checkpoint directory = " + checkpointDirPath); + } if (!checkpointDirPath.endsWith(File.separator)) { checkpointDirPath += File.separator; } checkpointDir = new File(checkpointDirPath); // Create the checkpoint directory if missing if (!checkpointDir.exists()) { + if (LOGGER.isLoggable(Level.INFO)) { + LOGGER.log(Level.INFO, "Checkpoint directory " + checkpointDirPath + " didn't exist. Creating one"); + } checkpointDir.mkdirs(); } lsnThreshold = checkpointProperties.getLsnThreshold(); @@ -82,25 +88,42 @@ public abstract class AbstractCheckpointManager implements ICheckpointManager { @Override public Checkpoint getLatest() throws ACIDException { // Read all checkpointObjects from the existing checkpoint files + LOGGER.log(Level.INFO, "Getting latest checkpoint"); File[] checkpoints = checkpointDir.listFiles(filter); if (checkpoints == null || checkpoints.length == 0) { + if (LOGGER.isLoggable(Level.INFO)) { + LOGGER.log(Level.INFO, + "Listing of files in the checkpoint dir returned " + (checkpoints == null ? "null" : "empty")); + } return null; } + if (LOGGER.isLoggable(Level.INFO)) { + LOGGER.log(Level.INFO, "Listing of files in the checkpoint dir returned " + Arrays.toString(checkpoints)); + } List<Checkpoint> checkpointObjectList = new ArrayList<>(); for (File file : checkpoints) { try { - LOGGER.log(Level.WARNING, "Reading checkpoint file: " + file.getAbsolutePath()); + if (LOGGER.isLoggable(Level.WARNING)) { + LOGGER.log(Level.WARNING, "Reading checkpoint file: " + file.getAbsolutePath()); + } String jsonString = new String(Files.readAllBytes(Paths.get(file.getAbsolutePath()))); checkpointObjectList.add(Checkpoint.fromJson(jsonString)); } catch (ClosedByInterruptException e) { Thread.currentThread().interrupt(); - LOGGER.log(Level.WARNING, "Interrupted while reading checkpoint file: " + file.getAbsolutePath(), e); + if (LOGGER.isLoggable(Level.WARNING)) { + LOGGER.log(Level.WARNING, "Interrupted while reading checkpoint file: " + file.getAbsolutePath(), + e); + } throw new ACIDException(e); } catch (IOException e) { // ignore corrupted checkpoint file - LOGGER.log(Level.WARNING, "Failed to read checkpoint file: " + file.getAbsolutePath(), e); + if (LOGGER.isLoggable(Level.WARNING)) { + LOGGER.log(Level.WARNING, "Failed to read checkpoint file: " + file.getAbsolutePath(), e); + } file.delete(); - LOGGER.log(Level.INFO, "Deleted corrupted checkpoint file: " + file.getAbsolutePath()); + if (LOGGER.isLoggable(Level.WARNING)) { + LOGGER.log(Level.WARNING, "Deleted corrupted checkpoint file: " + file.getAbsolutePath()); + } } } /** @@ -144,8 +167,8 @@ public abstract class AbstractCheckpointManager implements ICheckpointManager { } public Path getCheckpointPath(long checkpointTimestamp) { - return Paths.get(checkpointDir.getAbsolutePath() + File.separator + CHECKPOINT_FILENAME_PREFIX + Long - .toString(checkpointTimestamp)); + return Paths.get(checkpointDir.getAbsolutePath() + File.separator + CHECKPOINT_FILENAME_PREFIX + + Long.toString(checkpointTimestamp)); } protected void capture(long minMCTFirstLSN, boolean sharp) throws HyracksDataException { @@ -171,12 +194,24 @@ public abstract class AbstractCheckpointManager implements ICheckpointManager { private void persist(Checkpoint checkpoint) throws HyracksDataException { // Get checkpoint file path Path path = getCheckpointPath(checkpoint.getTimeStamp()); + + if (LOGGER.isLoggable(Level.INFO)) { + File file = path.toFile(); + LOGGER.log(Level.INFO, "Persisting checkpoint file to " + file + " which " + + (file.exists() ? "already exists" : "doesn't exist yet")); + } // Write checkpoint file to disk try (BufferedWriter writer = Files.newBufferedWriter(path)) { writer.write(checkpoint.asJson()); writer.flush(); } catch (IOException e) { - throw new HyracksDataException("Failed to write checkpoint to disk", e); + LOGGER.log(Level.SEVERE, "Failed to write checkpoint to disk", e); + throw HyracksDataException.create(e); + } + if (LOGGER.isLoggable(Level.INFO)) { + File file = path.toFile(); + LOGGER.log(Level.INFO, "Completed persisting checkpoint file to " + file + " which now " + + (file.exists() ? "exists" : " still doesn't exist")); } } @@ -185,8 +220,13 @@ public abstract class AbstractCheckpointManager implements ICheckpointManager { // Sort the filenames lexicographically to keep the latest checkpoint history files. Arrays.sort(checkpointFiles); for (int i = 0; i < checkpointFiles.length - historyToKeep; i++) { + if (LOGGER.isLoggable(Level.WARNING)) { + LOGGER.warning("Deleting checkpoint file at: " + checkpointFiles[i].getAbsolutePath()); + } if (!checkpointFiles[i].delete()) { - LOGGER.warning("Could not delete checkpoint file at: " + checkpointFiles[i].getAbsolutePath()); + if (LOGGER.isLoggable(Level.WARNING)) { + LOGGER.warning("Could not delete checkpoint file at: " + checkpointFiles[i].getAbsolutePath()); + } } } }
