diff --git a/engine/storage/image/src/org/apache/cloudstack/storage/image/TemplateServiceImpl.java b/engine/storage/image/src/org/apache/cloudstack/storage/image/TemplateServiceImpl.java index 4a7ef535038..9eef3992e3e 100644 --- a/engine/storage/image/src/org/apache/cloudstack/storage/image/TemplateServiceImpl.java +++ b/engine/storage/image/src/org/apache/cloudstack/storage/image/TemplateServiceImpl.java @@ -572,12 +572,21 @@ public class TemplateServiceImpl implements TemplateService { } TemplateObject tmplForCopy = (TemplateObject)_templateFactory.getTemplate(srcTemplate, destStore); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Setting source template url to " + url); + } tmplForCopy.setUrl(url); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Mark template_store_ref entry as Creating"); + } AsyncCallFuture future = new AsyncCallFuture(); DataObject templateOnStore = destStore.create(tmplForCopy); templateOnStore.processEvent(Event.CreateOnlyRequested); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Invoke datastore driver createAsync to create template on destination store"); + } TemplateOpContext context = new TemplateOpContext(null, (TemplateObject) templateOnStore, future); AsyncCallbackDispatcher caller = AsyncCallbackDispatcher.create(this); @@ -653,6 +662,9 @@ public class TemplateServiceImpl implements TemplateService { } protected Void copyTemplateCrossZoneCallBack(AsyncCallbackDispatcher callback, TemplateOpContext context) { + if (s_logger.isDebugEnabled()) { + s_logger.debug("Performing copy template cross zone callback after completion"); + } TemplateInfo destTemplate = context.getTemplate(); CreateCmdResult result = callback.getResult(); AsyncCallFuture future = context.getFuture(); diff --git a/engine/storage/src/org/apache/cloudstack/storage/RemoteHostEndPoint.java b/engine/storage/src/org/apache/cloudstack/storage/RemoteHostEndPoint.java index cd64ab2457c..369381358a8 100644 --- a/engine/storage/src/org/apache/cloudstack/storage/RemoteHostEndPoint.java +++ b/engine/storage/src/org/apache/cloudstack/storage/RemoteHostEndPoint.java @@ -43,6 +43,7 @@ import com.cloud.host.Host; import com.cloud.host.Status; import com.cloud.hypervisor.HypervisorGuruManager; import com.cloud.utils.component.ComponentContext; +import com.cloud.utils.concurrency.NamedThreadFactory; import com.cloud.utils.exception.CloudRuntimeException; public class RemoteHostEndPoint implements EndPoint { @@ -57,7 +58,7 @@ public class RemoteHostEndPoint implements EndPoint { private ScheduledExecutorService executor; public RemoteHostEndPoint() { - executor = Executors.newScheduledThreadPool(10); + executor = Executors.newScheduledThreadPool(10, new NamedThreadFactory("RemoteHostEndPoint")); } private void configure(long hostId, String hostAddress, String publicAddress) { @@ -170,6 +171,9 @@ public class RemoteHostEndPoint implements EndPoint { public void sendMessageAsync(Command cmd, AsyncCompletionCallback callback) { try { long newHostId = _hvGuruMgr.getGuruProcessedCommandTargetHost(this.hostId, cmd); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Sending command " + cmd.toString() + " to host: " + newHostId); + } agentMgr.send(newHostId, new Commands(cmd), new CmdRunner(callback)); } catch (AgentUnavailableException e) { throw new CloudRuntimeException("Unable to send message", e); diff --git a/engine/storage/src/org/apache/cloudstack/storage/image/BaseImageStoreDriverImpl.java b/engine/storage/src/org/apache/cloudstack/storage/image/BaseImageStoreDriverImpl.java index f77226df2e0..a415c9f05bb 100644 --- a/engine/storage/src/org/apache/cloudstack/storage/image/BaseImageStoreDriverImpl.java +++ b/engine/storage/src/org/apache/cloudstack/storage/image/BaseImageStoreDriverImpl.java @@ -113,15 +113,24 @@ public abstract class BaseImageStoreDriverImpl implements ImageStoreDriver { caller.setContext(context); if (data.getType() == DataObjectType.TEMPLATE) { caller.setCallback(caller.getTarget().createTemplateAsyncCallback(null, null)); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Downloading template to data store " + dataStore.getId()); + } _downloadMonitor.downloadTemplateToStorage(data, caller); } else if (data.getType() == DataObjectType.VOLUME) { caller.setCallback(caller.getTarget().createVolumeAsyncCallback(null, null)); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Downloading volume to data store " + dataStore.getId()); + } _downloadMonitor.downloadVolumeToStorage(data, caller); } } protected Void createTemplateAsyncCallback(AsyncCallbackDispatcher callback, CreateContext context) { + if (s_logger.isDebugEnabled()) { + s_logger.debug("Performing image store createTemplate async callback"); + } DownloadAnswer answer = callback.getResult(); DataObject obj = context.data; DataStore store = obj.getDataStore(); diff --git a/server/src/com/cloud/agent/manager/AgentAttache.java b/server/src/com/cloud/agent/manager/AgentAttache.java index dbdbd370312..2cedc4d474f 100755 --- a/server/src/com/cloud/agent/manager/AgentAttache.java +++ b/server/src/com/cloud/agent/manager/AgentAttache.java @@ -33,7 +33,6 @@ import java.util.concurrent.TimeUnit; import org.apache.log4j.Logger; -import com.cloud.agent.AgentManager; import com.cloud.agent.Listener; import com.cloud.agent.api.Answer; import com.cloud.agent.api.CheckHealthCommand; @@ -68,7 +67,7 @@ public abstract class AgentAttache { private static final Random s_rand = new Random(System.currentTimeMillis()); protected static final Comparator s_reqComparator = - new Comparator() { + new Comparator() { @Override public int compare(Request o1, Request o2) { long seq1 = o1.getSequence(); @@ -84,7 +83,7 @@ public abstract class AgentAttache { }; protected static final Comparator s_seqComparator = - new Comparator() { + new Comparator() { @Override public int compare(Object o1, Object o2) { long seq1 = ((Request) o1).getSequence(); @@ -110,9 +109,9 @@ public abstract class AgentAttache { protected AgentManagerImpl _agentMgr; public final static String[] s_commandsAllowedInMaintenanceMode = - new String[] { MaintainCommand.class.toString(), MigrateCommand.class.toString(), StopCommand.class.toString(), CheckVirtualMachineCommand.class.toString(), PingTestCommand.class.toString(), CheckHealthCommand.class.toString(), ReadyCommand.class.toString(), ShutdownCommand.class.toString(), SetupCommand.class.toString(), ClusterSyncCommand.class.toString(), CleanupNetworkRulesCmd.class.toString(), CheckNetworkCommand.class.toString() }; + new String[] { MaintainCommand.class.toString(), MigrateCommand.class.toString(), StopCommand.class.toString(), CheckVirtualMachineCommand.class.toString(), PingTestCommand.class.toString(), CheckHealthCommand.class.toString(), ReadyCommand.class.toString(), ShutdownCommand.class.toString(), SetupCommand.class.toString(), ClusterSyncCommand.class.toString(), CleanupNetworkRulesCmd.class.toString(), CheckNetworkCommand.class.toString() }; protected final static String[] s_commandsNotAllowedInConnectingMode = - new String[] { StartCommand.class.toString(), CreateCommand.class.toString() }; + new String[] { StartCommand.class.toString(), CreateCommand.class.toString() }; static { Arrays.sort(s_commandsAllowedInMaintenanceMode); Arrays.sort(s_commandsNotAllowedInConnectingMode); @@ -242,7 +241,7 @@ public abstract class AgentAttache { public int getQueueSize() { return _requests.size(); } - + public int getNonRecurringListenersSize() { List nonRecurringListenersList = new ArrayList(); if (_waitForList.isEmpty()) { @@ -258,7 +257,7 @@ public abstract class AgentAttache { s_logger.debug("Listener is " + entry.getValue() + " waiting on " + entry.getKey()); nonRecurringListenersList.add(monitor); } - } + } } return nonRecurringListenersList.size(); @@ -291,16 +290,16 @@ public abstract class AgentAttache { unregisterListener(seq); } } - - _agentMgr.notifyAnswersToMonitors(_id, seq, answers); - + + _agentMgr.notifyAnswersToMonitors(_id, seq, answers); + } finally { // we should always trigger next command execution, even in failure cases - otherwise in exception case all the remaining will be stuck in the sync queue forever if (resp.executeInSequence()) { sendNext(seq); } } - + return processed; } @@ -338,15 +337,26 @@ public abstract class AgentAttache { checkAvailability(req.getCommands()); long seq = req.getSequence(); - + if (s_logger.isDebugEnabled()) { + s_logger.debug("Request seq: " + seq); + } + if (listener != null) { registerListener(seq, listener); } else if (s_logger.isDebugEnabled()) { s_logger.debug(log(seq, "Routed from " + req.getManagementServerId())); } + if (s_logger.isDebugEnabled()) { + s_logger.debug("waiting to send " + seq); + } + synchronized(this) { try { + if (s_logger.isDebugEnabled()) { + s_logger.debug("entering synchronize block for sending " + seq); + } + if (isClosed()) { throw new AgentUnavailableException("The link to the agent has been closed", _id); } diff --git a/server/src/com/cloud/agent/manager/AgentManagerImpl.java b/server/src/com/cloud/agent/manager/AgentManagerImpl.java index 15cdc0c6e12..edc0d9d4c5c 100755 --- a/server/src/com/cloud/agent/manager/AgentManagerImpl.java +++ b/server/src/com/cloud/agent/manager/AgentManagerImpl.java @@ -538,6 +538,9 @@ public class AgentManagerImpl extends ManagerBase implements AgentManager, Handl } Request req = new Request(hostId, _nodeId, cmds, commands.stopOnError(), true); req.setSequence(agent.getNextSequence()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("AgentManager sending request"); + } agent.send(req, listener); return req.getSequence(); } diff --git a/server/src/com/cloud/storage/download/DownloadMonitorImpl.java b/server/src/com/cloud/storage/download/DownloadMonitorImpl.java index 2b1aa4e1bf2..4918bf55f1f 100755 --- a/server/src/com/cloud/storage/download/DownloadMonitorImpl.java +++ b/server/src/com/cloud/storage/download/DownloadMonitorImpl.java @@ -123,7 +123,7 @@ public class DownloadMonitorImpl extends ManagerBase implements DownloadMonitor ComponentContext.inject(dl); _agentMgr.registerForHostEvents(dl, true, false, false); - return true; + return true; } @Override @@ -153,7 +153,7 @@ public class DownloadMonitorImpl extends ManagerBase implements DownloadMonitor vmTemplateStore = new TemplateDataStoreVO(store.getId(), template.getId(), new Date(), 0, Status.NOT_DOWNLOADED, null, null, "jobid0000", null, template.getUri()); vmTemplateStore.setDataStoreRole(store.getRole()); - _vmTemplateStoreDao.persist(vmTemplateStore); + vmTemplateStore = _vmTemplateStoreDao.persist(vmTemplateStore); } else if ((vmTemplateStore.getJobId() != null) && (vmTemplateStore.getJobId().length() > 2)) { downloadJobExists = true; } @@ -176,7 +176,7 @@ public class DownloadMonitorImpl extends ManagerBase implements DownloadMonitor return; } DownloadListener dl = new DownloadListener(ep, store, template, _timer, this, dcmd, - callback); + callback); ComponentContext.inject(dl); // initialize those auto-wired field in download listener. if (downloadJobExists) { // due to handling existing download job issues, we still keep @@ -184,6 +184,7 @@ public class DownloadMonitorImpl extends ManagerBase implements DownloadMonitor // DownloadListener to use // new ObjectInDataStore.State transition. TODO: fix this later // to be able to remove downloadState from template_store_ref. + s_logger.info("found existing download job"); dl.setCurrState(vmTemplateStore.getDownloadState()); } @@ -192,6 +193,7 @@ public class DownloadMonitorImpl extends ManagerBase implements DownloadMonitor old = _listenerTemplateMap.put(vmTemplateStore, dl); } if (old != null) { + s_logger.info("abandon obsolete download listener"); old.abandon(); }