Repository: cloudstack Updated Branches: refs/heads/4.4 4807fa7de -> 4ade3fbeb
logging in clustering code, to find faulty vif plug on xenserver from clustered ms on nic orchestration for start command Project: http://git-wip-us.apache.org/repos/asf/cloudstack/repo Commit: http://git-wip-us.apache.org/repos/asf/cloudstack/commit/8cf67c0b Tree: http://git-wip-us.apache.org/repos/asf/cloudstack/tree/8cf67c0b Diff: http://git-wip-us.apache.org/repos/asf/cloudstack/diff/8cf67c0b Branch: refs/heads/4.4 Commit: 8cf67c0bf7b69556ec3ac73190f8918662a58870 Parents: 4807fa7 Author: Daan Hoogland <dhoogl...@schubergphilis.com> Authored: Tue Dec 23 12:21:41 2014 +0100 Committer: Daan Hoogland <dhoogl...@schubergphilis.com> Committed: Mon Jan 5 12:57:00 2015 +0100 ---------------------------------------------------------------------- core/src/com/cloud/agent/transport/Request.java | 19 ++++++---- .../com/cloud/agent/transport/RequestTest.java | 12 +++---- .../com/cloud/agent/manager/AgentAttache.java | 38 ++++++++++---------- .../cloud/agent/manager/AgentManagerImpl.java | 2 +- .../agent/manager/ClusteredAgentAttache.java | 18 +++++----- .../manager/ClusteredAgentManagerImpl.java | 35 +++++++++--------- .../manager/ClusteredDirectAgentAttache.java | 13 +++++-- .../cloud/agent/manager/DirectAgentAttache.java | 27 +++++++------- .../xen/resource/CitrixResourceBase.java | 3 ++ .../cloud/hypervisor/HypervisorGuruBase.java | 12 ++++++- .../utils/component/ComponentLifecycleBase.java | 3 -- 11 files changed, 105 insertions(+), 77 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/core/src/com/cloud/agent/transport/Request.java ---------------------------------------------------------------------- diff --git a/core/src/com/cloud/agent/transport/Request.java b/core/src/com/cloud/agent/transport/Request.java index b5890d9..89438b2 100755 --- a/core/src/com/cloud/agent/transport/Request.java +++ b/core/src/com/cloud/agent/transport/Request.java @@ -37,12 +37,13 @@ import com.google.gson.JsonArray; import com.google.gson.JsonDeserializationContext; import com.google.gson.JsonDeserializer; import com.google.gson.JsonElement; +import com.google.gson.JsonIOException; import com.google.gson.JsonNull; import com.google.gson.JsonParseException; import com.google.gson.JsonSerializationContext; import com.google.gson.JsonSerializer; +import com.google.gson.JsonSyntaxException; import com.google.gson.stream.JsonReader; - import com.cloud.agent.api.Answer; import com.cloud.agent.api.Command; import com.cloud.agent.api.SecStorageFirewallCfgCommand.PortConfig; @@ -362,7 +363,7 @@ public class Request { public void logD(String msg, boolean logContent) { if (s_logger.isDebugEnabled()) { - String log = log(msg, logContent, Level.DEBUG); + String log = generateLogString(msg, logContent, Level.DEBUG); if (log != null) { s_logger.debug(log); } @@ -371,12 +372,12 @@ public class Request { public void logT(String msg, boolean logD) { if (s_logger.isTraceEnabled()) { - String log = log(msg, true, Level.TRACE); + String log = generateLogString(msg, true, Level.TRACE); if (log != null) { s_logger.trace(log); } } else if (logD && s_logger.isDebugEnabled()) { - String log = log(msg, false, Level.DEBUG); + String log = generateLogString(msg, false, Level.DEBUG); if (log != null) { s_logger.debug(log); } @@ -385,15 +386,18 @@ public class Request { @Override public String toString() { - return log("", true, Level.DEBUG); + return generateLogString("", true, Level.DEBUG); } - protected String log(String msg, boolean logContent, Level level) { + protected String generateLogString(String msg, boolean logContent, Level level) { StringBuilder content = new StringBuilder(); if (logContent) { if (_cmds == null) { try { _cmds = s_gson.fromJson(_content, this instanceof Response ? Answer[].class : Command[].class); + } catch (JsonSyntaxException e) { + s_logger.error("Unable to convert to json due to syntax error: " + _content); + throw e; } catch (RuntimeException e) { s_logger.error("Unable to convert to json: " + _content); throw e; @@ -401,7 +405,7 @@ public class Request { } try { s_gogger.toJson(_cmds, content); - } catch (Throwable e) { + } catch (JsonIOException e) { StringBuilder buff = new StringBuilder(); for (Command cmd : _cmds) { buff.append(cmd.getClass().getSimpleName()).append("/"); @@ -411,6 +415,7 @@ public class Request { return ""; } if (content.length() <= (1 + _cmds.length * 3)) { + s_logger.info("not building log message for '" + content + "', _cmds.length == " + _cmds.length); return null; } } else { http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/core/test/com/cloud/agent/transport/RequestTest.java ---------------------------------------------------------------------- diff --git a/core/test/com/cloud/agent/transport/RequestTest.java b/core/test/com/cloud/agent/transport/RequestTest.java index 6ee0eda..d7116f8 100644 --- a/core/test/com/cloud/agent/transport/RequestTest.java +++ b/core/test/com/cloud/agent/transport/RequestTest.java @@ -73,7 +73,7 @@ public class RequestTest extends TestCase { Level level = logger.getLevel(); logger.setLevel(Level.DEBUG); - String log = sreq.log("Debug", true, Level.DEBUG); + String log = sreq.generateLogString("Debug", true, Level.DEBUG); assert (log.contains(UpdateHostPasswordCommand.class.getSimpleName())); assert (log.contains(SecStorageFirewallCfgCommand.class.getSimpleName())); assert (!log.contains(GetHostStatsCommand.class.getSimpleName())); @@ -81,7 +81,7 @@ public class RequestTest extends TestCase { assert (!log.contains("password")); logger.setLevel(Level.TRACE); - log = sreq.log("Trace", true, Level.TRACE); + log = sreq.generateLogString("Trace", true, Level.TRACE); assert (log.contains(UpdateHostPasswordCommand.class.getSimpleName())); assert (log.contains(SecStorageFirewallCfgCommand.class.getSimpleName())); assert (log.contains(GetHostStatsCommand.class.getSimpleName())); @@ -89,7 +89,7 @@ public class RequestTest extends TestCase { assert (!log.contains("password")); logger.setLevel(Level.INFO); - log = sreq.log("Info", true, Level.INFO); + log = sreq.generateLogString("Info", true, Level.INFO); assert (log == null); logger.setLevel(level); @@ -216,14 +216,14 @@ public class RequestTest extends TestCase { Level level = logger.getLevel(); logger.setLevel(Level.DEBUG); - String log = sreq.log("Debug", true, Level.DEBUG); + String log = sreq.generateLogString("Debug", true, Level.DEBUG); assert (log == null); - log = sreq.log("Debug", false, Level.DEBUG); + log = sreq.generateLogString("Debug", false, Level.DEBUG); assert (log != null); logger.setLevel(Level.TRACE); - log = sreq.log("Trace", true, Level.TRACE); + log = sreq.generateLogString("Trace", true, Level.TRACE); assert (log.contains(GetHostStatsCommand.class.getSimpleName())); s_logger.debug(log); http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/engine/orchestration/src/com/cloud/agent/manager/AgentAttache.java ---------------------------------------------------------------------- diff --git a/engine/orchestration/src/com/cloud/agent/manager/AgentAttache.java b/engine/orchestration/src/com/cloud/agent/manager/AgentAttache.java index 24a6fe7..bcda03e 100755 --- a/engine/orchestration/src/com/cloud/agent/manager/AgentAttache.java +++ b/engine/orchestration/src/com/cloud/agent/manager/AgentAttache.java @@ -189,7 +189,7 @@ public abstract class AgentAttache { protected synchronized void cancel(final long seq) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Cancelling.")); + s_logger.debug(generateLogString(seq, "Cancelling.")); } final Listener listener = _waitForList.remove(seq); if (listener != null) { @@ -209,13 +209,13 @@ public abstract class AgentAttache { return Collections.binarySearch(_requests, seq, s_seqComparator); } - protected String log(final long seq, final String msg) { + protected String generateLogString(final long seq, final String msg) { return "Seq " + _id + "-" + seq + ": " + msg; } protected void registerListener(final long seq, final Listener listener) { if (s_logger.isTraceEnabled()) { - s_logger.trace(log(seq, "Registering listener")); + s_logger.trace(generateLogString(seq, "Registering listener")); } if (listener.getTimeout() != -1) { s_listenerExecutor.schedule(new Alarm(seq), listener.getTimeout(), TimeUnit.SECONDS); @@ -225,7 +225,7 @@ public abstract class AgentAttache { protected Listener unregisterListener(final long sequence) { if (s_logger.isTraceEnabled()) { - s_logger.trace(log(sequence, "Unregistering listener")); + s_logger.trace(generateLogString(sequence, "Unregistering listener")); } return _waitForList.remove(sequence); } @@ -282,12 +282,12 @@ public abstract class AgentAttache { processed = true; } if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Unable to find listener.")); + s_logger.debug(generateLogString(seq, "Unable to find listener.")); } } else { processed = monitor.processAnswers(_id, seq, answers); if (s_logger.isTraceEnabled()) { - s_logger.trace(log(seq, (processed ? "" : " did not ") + " processed ")); + s_logger.trace(generateLogString(seq, (processed ? "" : " did not ") + " processed ")); } if (!monitor.isRecurring()) { @@ -315,7 +315,7 @@ public abstract class AgentAttache { it.remove(); final Listener monitor = entry.getValue(); if (s_logger.isDebugEnabled()) { - s_logger.debug(log(entry.getKey(), "Sending disconnect to " + monitor.getClass())); + s_logger.debug(generateLogString(entry.getKey(), "Sending disconnect to " + monitor.getClass())); } monitor.processDisconnect(_id, state); } @@ -347,7 +347,7 @@ public abstract class AgentAttache { if (listener != null) { registerListener(seq, listener); } else if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Routed from " + req.getManagementServerId())); + s_logger.debug(generateLogString(seq, "Routed from " + req.getManagementServerId())); } synchronized (this) { @@ -371,15 +371,15 @@ public abstract class AgentAttache { if (req.executeInSequence() && _currentSequence == null) { _currentSequence = seq; if (s_logger.isTraceEnabled()) { - s_logger.trace(log(seq, " is current sequence")); + s_logger.trace(generateLogString(seq, " is current sequence")); } } } catch (AgentUnavailableException e) { - s_logger.info(log(seq, "Unable to send due to " + e.getMessage())); + s_logger.info(generateLogString(seq, "Unable to send due to " + e.getMessage())); cancel(seq); throw e; } catch (Exception e) { - s_logger.warn(log(seq, "Unable to send due to "), e); + s_logger.warn(generateLogString(seq, "Unable to send due to "), e); cancel(seq); throw new AgentUnavailableException("Problem due to other exception " + e.getMessage(), _id); } @@ -398,7 +398,7 @@ public abstract class AgentAttache { try { answers = sl.waitFor(wait); } catch (final InterruptedException e) { - s_logger.debug(log(seq, "Interrupted")); + s_logger.debug(generateLogString(seq, "Interrupted")); } if (answers != null) { if (s_logger.isDebugEnabled()) { @@ -420,20 +420,20 @@ public abstract class AgentAttache { final Long current = _currentSequence; if (current != null && seq != current) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Waited too long.")); + s_logger.debug(generateLogString(seq, "Waited too long.")); } throw new OperationTimedoutException(req.getCommands(), _id, seq, wait, false); } if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Waiting some more time because this is the current command")); + s_logger.debug(generateLogString(seq, "Waiting some more time because this is the current command")); } } throw new OperationTimedoutException(req.getCommands(), _id, seq, wait * 2, true); } catch (OperationTimedoutException e) { - s_logger.warn(log(seq, "Timed out on " + req.toString())); + s_logger.warn(generateLogString(seq, "Timed out on " + req.toString())); cancel(seq); final Long current = _currentSequence; if (req.executeInSequence() && (current != null && current == seq)) { @@ -441,7 +441,7 @@ public abstract class AgentAttache { } throw e; } catch (Exception e) { - s_logger.warn(log(seq, "Exception while waiting for answer"), e); + s_logger.warn(generateLogString(seq, "Exception while waiting for answer"), e); cancel(seq); final Long current = _currentSequence; if (req.executeInSequence() && (current != null && current == seq)) { @@ -457,20 +457,20 @@ public abstract class AgentAttache { _currentSequence = null; if (_requests.isEmpty()) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "No more commands found")); + s_logger.debug(generateLogString(seq, "No more commands found")); } return; } Request req = _requests.pop(); if (s_logger.isDebugEnabled()) { - s_logger.debug(log(req.getSequence(), "Sending now. is current sequence.")); + s_logger.debug(generateLogString(req.getSequence(), "Sending now. is current sequence.")); } try { send(req); } catch (AgentUnavailableException e) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(req.getSequence(), "Unable to send the next sequence")); + s_logger.debug(generateLogString(req.getSequence(), "Unable to send the next sequence")); } cancel(req.getSequence()); } http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/engine/orchestration/src/com/cloud/agent/manager/AgentManagerImpl.java ---------------------------------------------------------------------- diff --git a/engine/orchestration/src/com/cloud/agent/manager/AgentManagerImpl.java b/engine/orchestration/src/com/cloud/agent/manager/AgentManagerImpl.java index 9e0dd30..83ffb0b 100755 --- a/engine/orchestration/src/com/cloud/agent/manager/AgentManagerImpl.java +++ b/engine/orchestration/src/com/cloud/agent/manager/AgentManagerImpl.java @@ -115,7 +115,7 @@ import com.cloud.utils.time.InaccurateClock; **/ @Local(value = {AgentManager.class}) public class AgentManagerImpl extends ManagerBase implements AgentManager, HandlerFactory, Configurable { - protected static final Logger s_logger = Logger.getLogger(AgentManagerImpl.class); + private static final Logger s_logger = Logger.getLogger(AgentManagerImpl.class); protected static final Logger status_logger = Logger.getLogger(Status.class); /** http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentAttache.java ---------------------------------------------------------------------- diff --git a/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentAttache.java b/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentAttache.java index 306c47f..02be2e4 100755 --- a/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentAttache.java +++ b/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentAttache.java @@ -92,7 +92,7 @@ public class ClusteredAgentAttache extends ConnectedAgentAttache implements Rout String peerName = synchronous.getPeer(); if (peerName != null) { if (s_clusteredAgentMgr != null) { - s_logger.debug(log(seq, "Forwarding to peer to cancel due to timeout")); + s_logger.debug(generateLogString(seq, "Forwarding to peer to cancel due to timeout")); s_clusteredAgentMgr.cancel(peerName, _id, seq, "Timed Out"); } else { s_logger.error("Unable to forward cancel, ClusteredAgentAttache is not properly initialized"); @@ -108,12 +108,12 @@ public class ClusteredAgentAttache extends ConnectedAgentAttache implements Rout @Override public void routeToAgent(final byte[] data) throws AgentUnavailableException { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(Request.getSequence(data), "Routing from " + Request.getManagementServerId(data))); + s_logger.debug(generateLogString(Request.getSequence(data), "Routing from " + Request.getManagementServerId(data))); } if (_link == null) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(Request.getSequence(data), "Link is closed")); + s_logger.debug(generateLogString(Request.getSequence(data), "Link is closed")); } throw new AgentUnavailableException("Link is closed", _id); } @@ -122,13 +122,13 @@ public class ClusteredAgentAttache extends ConnectedAgentAttache implements Rout _link.send(data); } catch (ClosedChannelException e) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(Request.getSequence(data), "Channel is closed")); + s_logger.debug(generateLogString(Request.getSequence(data), "Channel is closed")); } throw new AgentUnavailableException("Channel to agent is closed", _id); } catch (NullPointerException e) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(Request.getSequence(data), "Link is closed")); + s_logger.debug(generateLogString(Request.getSequence(data), "Link is closed")); } // Note: since this block is not in synchronized. It is possible for _link to become null. throw new AgentUnavailableException("Channel to agent is null", _id); @@ -151,7 +151,7 @@ public class ClusteredAgentAttache extends ConnectedAgentAttache implements Rout if (_transferMode) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Holding request as the corresponding agent is in transfer mode: ")); + s_logger.debug(generateLogString(seq, "Holding request as the corresponding agent is in transfer mode: ")); } synchronized (this) { @@ -177,7 +177,7 @@ public class ClusteredAgentAttache extends ConnectedAgentAttache implements Rout ch = s_clusteredAgentMgr.connectToPeer(peerName, ch); if (ch == null) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Unable to forward " + req.toString())); + s_logger.debug(generateLogString(seq, "Unable to forward " + req.toString())); } continue; } @@ -189,7 +189,7 @@ public class ClusteredAgentAttache extends ConnectedAgentAttache implements Rout try { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Forwarding " + req.toString() + " to " + peerName)); + s_logger.debug(generateLogString(seq, "Forwarding " + req.toString() + " to " + peerName)); } if (req.executeInSequence() && listener != null && listener instanceof SynchronousListener) { SynchronousListener synchronous = (SynchronousListener)listener; @@ -200,7 +200,7 @@ public class ClusteredAgentAttache extends ConnectedAgentAttache implements Rout return; } catch (IOException e) { if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Error on connecting to management node: " + req.toString() + " try = " + i)); + s_logger.debug(generateLogString(seq, "Error on connecting to management node: " + req.toString() + " try = " + i)); } if (s_logger.isInfoEnabled()) { http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentManagerImpl.java ---------------------------------------------------------------------- diff --git a/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentManagerImpl.java b/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentManagerImpl.java index 01508a4..b404867 100755 --- a/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentManagerImpl.java +++ b/engine/orchestration/src/com/cloud/agent/manager/ClusteredAgentManagerImpl.java @@ -79,6 +79,7 @@ import com.cloud.cluster.agentlb.dao.HostTransferMapDao; import com.cloud.cluster.dao.ManagementServerHostDao; import com.cloud.exception.AgentUnavailableException; import com.cloud.exception.OperationTimedoutException; +import com.cloud.exception.UnsupportedVersionException; import com.cloud.host.Host; import com.cloud.host.HostVO; import com.cloud.host.Status; @@ -96,7 +97,7 @@ import com.cloud.utils.nio.Task; @Local(value = {AgentManager.class, ClusteredAgentRebalanceService.class}) public class ClusteredAgentManagerImpl extends AgentManagerImpl implements ClusterManagerListener, ClusteredAgentRebalanceService { - final static Logger s_logger = Logger.getLogger(ClusteredAgentManagerImpl.class); + private final static Logger s_logger = Logger.getLogger(ClusteredAgentManagerImpl.class); private static final ScheduledExecutorService s_transferExecutor = Executors.newScheduledThreadPool(2, new NamedThreadFactory("Cluster-AgentRebalancingExecutor")); private final long rebalanceTimeOut = 300000; // 5 mins - after this time remove the agent from the transfer list @@ -389,13 +390,17 @@ public class ClusteredAgentManagerImpl extends AgentManagerImpl implements Clust } protected static void logT(byte[] bytes, final String msg) { - s_logger.trace("Seq " + Request.getAgentId(bytes) + "-" + Request.getSequence(bytes) + ": MgmtId " + Request.getManagementServerId(bytes) + ": " + - (Request.isRequest(bytes) ? "Req: " : "Resp: ") + msg); + if(s_logger.isTraceEnabled()) { + s_logger.trace("Seq " + Request.getAgentId(bytes) + "-" + Request.getSequence(bytes) + ": MgmtId " + Request.getManagementServerId(bytes) + ": " + + (Request.isRequest(bytes) ? "Req: " : "Resp: ") + msg); + } } protected static void logD(byte[] bytes, final String msg) { - s_logger.debug("Seq " + Request.getAgentId(bytes) + "-" + Request.getSequence(bytes) + ": MgmtId " + Request.getManagementServerId(bytes) + ": " + - (Request.isRequest(bytes) ? "Req: " : "Resp: ") + msg); + if(s_logger.isDebugEnabled()) { + s_logger.debug("Seq " + Request.getAgentId(bytes) + "-" + Request.getSequence(bytes) + ": MgmtId " + Request.getManagementServerId(bytes) + ": " + + (Request.isRequest(bytes) ? "Req: " : "Resp: ") + msg); + } } protected static void logI(byte[] bytes, final String msg) { @@ -408,12 +413,15 @@ public class ClusteredAgentManagerImpl extends AgentManagerImpl implements Clust SocketChannel ch = null; SSLEngine sslEngine = null; while (i++ < 5) { + String msg = null; + try { + msg = Request.parse(bytes).toString(); + } catch (ClassNotFoundException | UnsupportedVersionException e1) { + s_logger.debug("can't parse bytes to message: " + bytes); + } ch = connectToPeer(peer, ch); if (ch == null) { - try { - logD(bytes, "Unable to route to peer: " + Request.parse(bytes).toString()); - } catch (Exception e) { - } + logD(bytes, "Unable to route to peer: " + msg); return false; } sslEngine = getSSLEngine(peer); @@ -422,16 +430,11 @@ public class ClusteredAgentManagerImpl extends AgentManagerImpl implements Clust return false; } try { - if (s_logger.isDebugEnabled()) { - logD(bytes, "Routing to peer"); - } + logD(bytes, "Routing to peer"); Link.write(ch, new ByteBuffer[] {ByteBuffer.wrap(bytes)}, sslEngine); return true; } catch (IOException e) { - try { - logI(bytes, "Unable to route to peer: " + Request.parse(bytes).toString() + " due to " + e.getMessage()); - } catch (Exception ex) { - } + logI(bytes, "Unable to route to peer: " + msg + " due to " + e.getMessage()); } } return false; http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/engine/orchestration/src/com/cloud/agent/manager/ClusteredDirectAgentAttache.java ---------------------------------------------------------------------- diff --git a/engine/orchestration/src/com/cloud/agent/manager/ClusteredDirectAgentAttache.java b/engine/orchestration/src/com/cloud/agent/manager/ClusteredDirectAgentAttache.java index d7c0827..ec5354a 100755 --- a/engine/orchestration/src/com/cloud/agent/manager/ClusteredDirectAgentAttache.java +++ b/engine/orchestration/src/com/cloud/agent/manager/ClusteredDirectAgentAttache.java @@ -16,6 +16,8 @@ // under the License. package com.cloud.agent.manager; +import org.apache.log4j.Logger; + import com.cloud.agent.transport.Request; import com.cloud.agent.transport.Response; import com.cloud.exception.AgentUnavailableException; @@ -24,6 +26,7 @@ import com.cloud.resource.ServerResource; import com.cloud.utils.exception.CloudRuntimeException; public class ClusteredDirectAgentAttache extends DirectAgentAttache implements Routable { + private final static Logger s_logger = Logger.getLogger(ClusteredDirectAgentAttache.class); private final ClusteredAgentManagerImpl _mgr; private final long _nodeId; @@ -40,14 +43,17 @@ public class ClusteredDirectAgentAttache extends DirectAgentAttache implements R try { req = Request.parse(data); } catch (ClassNotFoundException e) { - throw new CloudRuntimeException("Unable to rout to an agent ", e); + throw new CloudRuntimeException("Unable to route to an agent; no implementation found ", e); } catch (UnsupportedVersionException e) { - throw new CloudRuntimeException("Unable to rout to an agent ", e); + throw new CloudRuntimeException("Unable to route to an agent; protocol not supported ", e); } if (req instanceof Response) { super.process(((Response)req).getAnswers()); } else { + if(s_logger.isDebugEnabled()) { + s_logger.debug("sending request " + req.getSequence() + ", command: " + req.getCommand()); + } super.send(req); } } @@ -58,6 +64,9 @@ public class ClusteredDirectAgentAttache extends DirectAgentAttache implements R if (mgmtId != -1 && mgmtId != _nodeId) { _mgr.routeToPeer(Long.toString(mgmtId), response.getBytes()); if (response.executeInSequence()) { + if(s_logger.isDebugEnabled()) { + s_logger.debug("sending response " + response.getSequence()); + } sendNext(response.getSequence()); } return true; http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/engine/orchestration/src/com/cloud/agent/manager/DirectAgentAttache.java ---------------------------------------------------------------------- diff --git a/engine/orchestration/src/com/cloud/agent/manager/DirectAgentAttache.java b/engine/orchestration/src/com/cloud/agent/manager/DirectAgentAttache.java index 2039a96..f3459d8 100755 --- a/engine/orchestration/src/com/cloud/agent/manager/DirectAgentAttache.java +++ b/engine/orchestration/src/com/cloud/agent/manager/DirectAgentAttache.java @@ -94,9 +94,9 @@ public class DirectAgentAttache extends AgentAttache { @Override public void send(Request req) throws AgentUnavailableException { - req.logD("Executing: ", true); if (req instanceof Response) { Response resp = (Response)req; + resp.logD("Received: ", true); Answer[] answers = resp.getAnswers(); if (answers != null && answers[0] instanceof StartupAnswer) { StartupAnswer startup = (StartupAnswer)answers[0]; @@ -104,6 +104,7 @@ public class DirectAgentAttache extends AgentAttache { _futures.add(_agentMgr.getCronJobPool().scheduleAtFixedRate(producePingTask(), interval, interval, TimeUnit.SECONDS)); } } else { + req.logD("Executing: ", true); Command[] cmds = req.getCommands(); if (cmds.length > 0 && !(cmds[0] instanceof CronCommand)) { queueTask(new Task(req)); @@ -117,7 +118,7 @@ public class DirectAgentAttache extends AgentAttache { @Override public void process(Answer[] answers) { - if (answers != null && answers[0] instanceof StartupAnswer) { + if (answers != null && answers.length > 0 && answers[0] instanceof StartupAnswer) { StartupAnswer startup = (StartupAnswer)answers[0]; int interval = startup.getPingInterval(); s_logger.info("StartupAnswer received " + startup.getHostId() + " Interval = " + interval); @@ -220,7 +221,7 @@ public class DirectAgentAttache extends AgentAttache { Response resp = new Response(_req, answers.toArray(new Answer[answers.size()])); processAnswers(seq, resp); } catch (Exception e) { - s_logger.warn(log(seq, "Exception caught in bailout "), e); + s_logger.warn(generateLogString(seq, "Exception caught in bailout "), e); } } @@ -239,7 +240,7 @@ public class DirectAgentAttache extends AgentAttache { boolean stopOnError = _req.stopOnError(); if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Executing request")); + s_logger.debug(generateLogString(seq, "Executing request")); } ArrayList<Answer> answers = new ArrayList<Answer>(cmds.length); for (int i = 0; i < cmds.length; i++) { @@ -255,13 +256,13 @@ public class DirectAgentAttache extends AgentAttache { answer = new Answer(cmds[i], false, "Agent is disconnected"); } } catch (Exception e) { - s_logger.warn(log(seq, "Exception Caught while executing command"), e); + s_logger.warn(generateLogString(seq, "Exception Caught while executing command"), e); answer = new Answer(cmds[i], false, e.toString()); } answers.add(answer); if (!answer.getResult() && stopOnError) { if (i < cmds.length - 1 && s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Cancelling because one of the answers is false and it is stop on error.")); + s_logger.debug(generateLogString(seq, "Cancelling because one of the answers is false and it is stop on error.")); } break; } @@ -269,12 +270,12 @@ public class DirectAgentAttache extends AgentAttache { Response resp = new Response(_req, answers.toArray(new Answer[answers.size()])); if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Response Received: ")); + s_logger.debug(generateLogString(seq, "Response Received: ")); } processAnswers(seq, resp); } catch (Exception e) { - s_logger.warn(log(seq, "Exception caught "), e); + s_logger.warn(generateLogString(seq, "Exception caught "), e); } finally { _outstandingCronTaskCount.decrementAndGet(); } @@ -297,7 +298,7 @@ public class DirectAgentAttache extends AgentAttache { boolean stopOnError = _req.stopOnError(); if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Executing request")); + s_logger.debug(generateLogString(seq, "Executing request")); } ArrayList<Answer> answers = new ArrayList<Answer>(cmds.length); for (int i = 0; i < cmds.length; i++) { @@ -313,13 +314,13 @@ public class DirectAgentAttache extends AgentAttache { answer = new Answer(cmds[i], false, "Agent is disconnected"); } } catch (Exception e) { - s_logger.warn(log(seq, "Exception Caught while executing command"), e); + s_logger.warn(generateLogString(seq, "Exception Caught while executing command"), e); answer = new Answer(cmds[i], false, e.toString()); } answers.add(answer); if (!answer.getResult() && stopOnError) { if (i < cmds.length - 1 && s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Cancelling because one of the answers is false and it is stop on error.")); + s_logger.debug(generateLogString(seq, "Cancelling because one of the answers is false and it is stop on error.")); } break; } @@ -327,12 +328,12 @@ public class DirectAgentAttache extends AgentAttache { Response resp = new Response(_req, answers.toArray(new Answer[answers.size()])); if (s_logger.isDebugEnabled()) { - s_logger.debug(log(seq, "Response Received: ")); + s_logger.debug(generateLogString(seq, "Response Received: ")); } processAnswers(seq, resp); } catch (Exception e) { - s_logger.warn(log(seq, "Exception caught "), e); + s_logger.warn(generateLogString(seq, "Exception caught "), e); } finally { _outstandingTaskCount.decrementAndGet(); scheduleFromQueue(); http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/plugins/hypervisors/xen/src/com/cloud/hypervisor/xen/resource/CitrixResourceBase.java ---------------------------------------------------------------------- diff --git a/plugins/hypervisors/xen/src/com/cloud/hypervisor/xen/resource/CitrixResourceBase.java b/plugins/hypervisors/xen/src/com/cloud/hypervisor/xen/resource/CitrixResourceBase.java index 1e55e48..580750f 100644 --- a/plugins/hypervisors/xen/src/com/cloud/hypervisor/xen/resource/CitrixResourceBase.java +++ b/plugins/hypervisors/xen/src/com/cloud/hypervisor/xen/resource/CitrixResourceBase.java @@ -1090,6 +1090,9 @@ public abstract class CitrixResourceBase implements ServerResource, HypervisorRe if (s_logger.isDebugEnabled()) { s_logger.debug("Creating VIF for " + vmName + " on nic " + nic); } + if (s_logger.isTraceEnabled()) { + s_logger.trace("Creating VIF on nic [" + nic.getDeviceId() + ", " + nic.getUuid() + "] on net " + nic.getNetworkUuid()); + } VIF.Record vifr = new VIF.Record(); vifr.VM = vm; vifr.device = Integer.toString(nic.getDeviceId()); http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/server/src/com/cloud/hypervisor/HypervisorGuruBase.java ---------------------------------------------------------------------- diff --git a/server/src/com/cloud/hypervisor/HypervisorGuruBase.java b/server/src/com/cloud/hypervisor/HypervisorGuruBase.java index e2520d2..0cbaf6d 100644 --- a/server/src/com/cloud/hypervisor/HypervisorGuruBase.java +++ b/server/src/com/cloud/hypervisor/HypervisorGuruBase.java @@ -17,11 +17,14 @@ package com.cloud.hypervisor; import com.cloud.network.dao.NetworkVO; + import java.util.List; import java.util.Map; import javax.inject.Inject; +import org.apache.log4j.Logger; + import com.cloud.agent.api.Command; import com.cloud.agent.api.to.DiskTO; import com.cloud.agent.api.to.NicTO; @@ -48,6 +51,7 @@ import com.cloud.vm.dao.UserVmDetailsDao; import com.cloud.vm.dao.VMInstanceDao; public abstract class HypervisorGuruBase extends AdapterBase implements HypervisorGuru { + private static final Logger s_logger = Logger.getLogger(HypervisorGuruBase.class); @Inject VMTemplateDetailsDao _templateDetailsDao; @@ -92,10 +96,16 @@ public abstract class HypervisorGuruBase extends AdapterBase implements Hypervis to.setSecurityGroupEnabled(profile.isSecurityGroupEnabled()); NetworkVO network = _networkDao.findById(profile.getNetworkId()); + if(s_logger.isTraceEnabled()) { + s_logger.trace(profile.getNetworkId() + " resulted in net id " + network.getUuid()); + } to.setNetworkUuid(network.getUuid()); - // Workaround to make sure the TO has the UUID we need for Niciri integration + // Workaround to make sure the TO has the UUID we need for Nicira integration NicVO nicVO = _nicDao.findById(profile.getId()); + if(s_logger.isTraceEnabled()) { + s_logger.trace(profile.getId() + " resulted in nic id " + nicVO.getUuid()); + } to.setUuid(nicVO.getUuid()); //check whether the this nic has secondary ip addresses set //set nic secondary ip address in NicTO which are used for security group http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8cf67c0b/utils/src/com/cloud/utils/component/ComponentLifecycleBase.java ---------------------------------------------------------------------- diff --git a/utils/src/com/cloud/utils/component/ComponentLifecycleBase.java b/utils/src/com/cloud/utils/component/ComponentLifecycleBase.java index 829dc9b..cf5d2ca 100644 --- a/utils/src/com/cloud/utils/component/ComponentLifecycleBase.java +++ b/utils/src/com/cloud/utils/component/ComponentLifecycleBase.java @@ -24,10 +24,7 @@ import java.util.Map; import javax.naming.ConfigurationException; -import org.apache.log4j.Logger; - public class ComponentLifecycleBase implements ComponentLifecycle { - private static final Logger s_logger = Logger.getLogger(ComponentLifecycleBase.class); protected String _name; protected int _runLevel;