CLOUDSTACK-3513: add debug message to diagnose copyIso issue on

automation setup where DownloadCommand is never sent.
This commit is contained in:
Min Chen 2013-07-18 16:01:32 -07:00
parent ca1f8a6632
commit e1c17bd853
6 changed files with 56 additions and 16 deletions

View File

@ -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<TemplateApiResult> future = new AsyncCallFuture<TemplateApiResult>();
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<TemplateApiResult> context = new TemplateOpContext<TemplateApiResult>(null,
(TemplateObject) templateOnStore, future);
AsyncCallbackDispatcher<TemplateServiceImpl, CreateCmdResult> caller = AsyncCallbackDispatcher.create(this);
@ -653,6 +662,9 @@ public class TemplateServiceImpl implements TemplateService {
}
protected Void copyTemplateCrossZoneCallBack(AsyncCallbackDispatcher<TemplateServiceImpl, CreateCmdResult> callback, TemplateOpContext<TemplateApiResult> 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<TemplateApiResult> future = context.getFuture();

View File

@ -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<Answer> 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);

View File

@ -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<? extends BaseImageStoreDriverImpl, DownloadAnswer> callback,
CreateContext<CreateCmdResult> 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();

View File

@ -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<Request> s_reqComparator =
new Comparator<Request>() {
new Comparator<Request>() {
@Override
public int compare(Request o1, Request o2) {
long seq1 = o1.getSequence();
@ -84,7 +83,7 @@ public abstract class AgentAttache {
};
protected static final Comparator<Object> s_seqComparator =
new Comparator<Object>() {
new Comparator<Object>() {
@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<Listener> nonRecurringListenersList = new ArrayList<Listener>();
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);
}

View File

@ -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();
}

View File

@ -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();
}