From 7197b3f4563d32bfbf7a205599750537d151a54c Mon Sep 17 00:00:00 2001 From: Andra Cismaru Date: Fri, 15 Jul 2016 18:56:43 -0700 Subject: [PATCH] Logging fixes, show actual timestamp of event Closes-Bug: #1549061 Sylog of Vcenter-plugin to show actual timestamp of event and also avoid repeated showing update Change-Id: I5afbf4d77038682cb19821b1a40f6f3386028f63 --- src/net/juniper/contrail/vcenter/MainDB.java | 2 - .../contrail/vcenter/VCenterEventHandler.java | 40 +++++-------- .../contrail/vcenter/VCenterNotify.java | 58 ++++++++++--------- 3 files changed, 43 insertions(+), 57 deletions(-) diff --git a/src/net/juniper/contrail/vcenter/MainDB.java b/src/net/juniper/contrail/vcenter/MainDB.java index 95627e2..ce70415 100644 --- a/src/net/juniper/contrail/vcenter/MainDB.java +++ b/src/net/juniper/contrail/vcenter/MainDB.java @@ -220,8 +220,6 @@ public static void sync(VCenterDB _vcenterDB, VncDB _vncDB, Mode _mode) sync(oldVMs, vmwareVMs); printInfo(); - - s_logger.info("\nSync complete, waiting for events\n"); } private static void printInfo() { diff --git a/src/net/juniper/contrail/vcenter/VCenterEventHandler.java b/src/net/juniper/contrail/vcenter/VCenterEventHandler.java index a24ab50..56d0d07 100644 --- a/src/net/juniper/contrail/vcenter/VCenterEventHandler.java +++ b/src/net/juniper/contrail/vcenter/VCenterEventHandler.java @@ -30,33 +30,18 @@ import com.vmware.vim25.VmRenamedEvent; public class VCenterEventHandler { - Event event; VCenterDB vcenterDB; VncDB vncDB; - private final Logger s_logger = + private static final Logger s_logger = Logger.getLogger(VCenterEventHandler.class); - VCenterEventHandler(Event event, VCenterDB vcenterDB, VncDB vncDB) { - this.event = event; + VCenterEventHandler(VCenterDB vcenterDB, VncDB vncDB) { this.vcenterDB = vcenterDB; this.vncDB = vncDB; } - private void printEvent() { - s_logger.info("==============="); - s_logger.info("\nEvent Details follows:"); - - s_logger.info("\n----------" + "\n Event ID: " - + event.getKey() + "\n Event: " - + event.getClass().getName() - + "\n FullFormattedMessage: " - + event.getFullFormattedMessage() - + "\n----------\n"); - } - - public void handle() throws Exception { - printEvent(); - + public void handle(Event event) throws Exception { + s_logger.info("Process event " + event.getFullFormattedMessage()); if (event instanceof VmCreatedEvent || event instanceof VmClonedEvent || event instanceof VmDeployedEvent @@ -69,21 +54,22 @@ public void handle() throws Exception { || event instanceof VmMigratedEvent || event instanceof VmPoweredOnEvent || event instanceof VmPoweredOffEvent) { - handleVmUpdateEvent(); + handleVmUpdateEvent(event); } else if (event instanceof VmRemovedEvent) { - handleVmDeleteEvent(); + handleVmDeleteEvent(event); } else if (event instanceof DVPortgroupCreatedEvent || event instanceof DVPortgroupReconfiguredEvent || event instanceof DVPortgroupRenamedEvent) { - handleNetworkUpdateEvent(); + handleNetworkUpdateEvent(event); } else if (event instanceof DVPortgroupDestroyedEvent) { - handleNetworkDeleteEvent(); + handleNetworkDeleteEvent(event); } else { handleEvent(event); } + s_logger.info("Done processing event " + event.getFullFormattedMessage()); } - private void handleVmUpdateEvent() throws Exception { + private void handleVmUpdateEvent(Event event) throws Exception { VirtualMachineInfo newVmInfo = null; try { @@ -104,7 +90,7 @@ private void handleVmUpdateEvent() throws Exception { } } - private void handleVmDeleteEvent() throws Exception { + private void handleVmDeleteEvent(Event event) throws Exception { VirtualMachineInfo vmInfo = MainDB.getVmByName(event.getVm().getName()); if (vmInfo == null) { @@ -115,7 +101,7 @@ private void handleVmDeleteEvent() throws Exception { vmInfo.delete(vncDB); } - private void handleNetworkUpdateEvent() throws Exception { + private void handleNetworkUpdateEvent(Event event) throws Exception { VirtualNetworkInfo newVnInfo = null; try { @@ -137,7 +123,7 @@ private void handleNetworkUpdateEvent() throws Exception { } } - private void handleNetworkDeleteEvent() throws Exception { + private void handleNetworkDeleteEvent(Event event) throws Exception { VirtualNetworkInfo vnInfo = MainDB.getVnByName(event.getNet().getName()); diff --git a/src/net/juniper/contrail/vcenter/VCenterNotify.java b/src/net/juniper/contrail/vcenter/VCenterNotify.java index 4ec1576..bc17c52 100644 --- a/src/net/juniper/contrail/vcenter/VCenterNotify.java +++ b/src/net/juniper/contrail/vcenter/VCenterNotify.java @@ -24,7 +24,6 @@ import com.vmware.vim25.SelectionSpec; import com.vmware.vim25.UpdateSet; import com.vmware.vim25.VirtualMachineToolsRunningStatus; -import com.vmware.vim25.VmEvent; import com.vmware.vim25.WaitOptions; import com.vmware.vim25.mo.EventHistoryCollector; import com.vmware.vim25.mo.EventManager; @@ -44,7 +43,6 @@ import com.google.common.base.Throwables; import com.vmware.vim25.InvalidState; import org.apache.log4j.Logger; -import java.net.SocketTimeoutException; /** * @author Sachchidanand Vaidya @@ -57,6 +55,7 @@ public class VCenterNotify implements Runnable Logger.getLogger(VCenterNotify.class); static volatile VCenterDB vcenterDB = null; static volatile VncDB vncDB; + private VCenterEventHandler eventHandler; private static boolean vCenterConnected = false; private final static String[] guestProps = { "guest.toolsRunningStatus", "guest.net" }; private final static String[] ipPoolProps = { "summary.ipPoolId" }; @@ -100,6 +99,8 @@ public VCenterNotify( default: vncDB = new VncDB(_apiServerAddress, _apiServerPort, mode); } + + eventHandler = new VCenterEventHandler(vcenterDB, vncDB); } public static VCenterDB getVcenterDB() { @@ -303,9 +304,6 @@ private void handleUpdate(UpdateSet update) throws Exception void handleChanges(ObjectUpdate oUpdate) throws Exception { - s_logger.info("+++++++++++++Received vcenter update of type " - + oUpdate.getKind() + "+++++++++++++"); - PropertyChange[] changes = oUpdate.getChangeSet(); if (changes == null) { return; @@ -323,6 +321,7 @@ void handleChanges(ObjectUpdate oUpdate) throws Exception PropertyChangeOp op = changes[pci].getOp(); if (op!= PropertyChangeOp.remove) { if (propName.equals("summary.ipPoolId")) { + s_logger.info("Received summary.ipPoolId property change"); Integer newPoolId = (Integer)value; ManagedObjectReference mor = oUpdate.getObj(); if (watchedVNs.containsKey(mor.getVal())) { @@ -331,6 +330,7 @@ void handleChanges(ObjectUpdate oUpdate) throws Exception if ((oldPoolId == null && newPoolId == null) || (oldPoolId != null && newPoolId != null && oldPoolId.equals(newPoolId))) { + s_logger.info("Done processing property update, nothing changed"); continue; } VirtualNetworkInfo newVnInfo = new VirtualNetworkInfo(vnInfo); @@ -343,9 +343,12 @@ void handleChanges(ObjectUpdate oUpdate) throws Exception vnInfo.update(newVnInfo, vncDB); } } + s_logger.info("Done processing property update"); } else if (propName.equals("guest.toolsRunningStatus")) { + s_logger.info("Received guest.toolsRunningStatus property change"); toolsRunningStatus = (String)value; } else if (value instanceof ArrayOfEvent) { + s_logger.info("Received ArrayOfEvent"); ArrayOfEvent aoe = (ArrayOfEvent) value; Event[] evts = aoe.getEvent(); if (evts == null) { @@ -357,15 +360,12 @@ void handleChanges(ObjectUpdate oUpdate) throws Exception if (anEvent == null) { continue; } - s_logger.info("\n----------" + "\n Event ID: " - + anEvent.getKey() + "\n Event: " - + anEvent.getClass().getName() - + "\n FullFormattedMessage: " - + anEvent.getFullFormattedMessage() - + "\n----------\n"); + printEvent(anEvent); } + s_logger.info("Done processing array of events"); } else if ((value instanceof EnteredMaintenanceModeEvent) || (value instanceof HostConnectionLostEvent)) { Event anEvent = (Event) value; + printEvent(anEvent); String vRouterIpAddress = vcenterDB.esxiToVRouterIpMap.get(anEvent.getHost().getName()); if (vRouterIpAddress != null) { VCenterDB.vRouterActiveMap.put(vRouterIpAddress, false); @@ -373,8 +373,10 @@ void handleChanges(ObjectUpdate oUpdate) throws Exception } else { s_logger.info("\nNot managing the host " + vRouterIpAddress +" inactive"); } + s_logger.info("Done processing event " + anEvent.getFullFormattedMessage()); } else if ((value instanceof ExitMaintenanceModeEvent) || (value instanceof HostConnectedEvent)) { Event anEvent = (Event) value; + printEvent(anEvent); String vRouterIpAddress = vcenterDB.esxiToVRouterIpMap.get(anEvent.getHost().getName()); if (vRouterIpAddress != null) { VCenterDB.vRouterActiveMap.put(vRouterIpAddress, true); @@ -382,15 +384,16 @@ void handleChanges(ObjectUpdate oUpdate) throws Exception } else { s_logger.info("\nNot managing the host " + vRouterIpAddress +" inactive"); } + s_logger.info("Done processing event " + anEvent.getFullFormattedMessage()); } else if (value instanceof ArrayOfGuestNicInfo) { - s_logger.info("Received update array of GuestNics"); + s_logger.info("Received event update array of GuestNics"); ArrayOfGuestNicInfo aog = (ArrayOfGuestNicInfo) value; nics = aog.getGuestNicInfo(); } else if (value instanceof Event) { - VCenterEventHandler handler = new VCenterEventHandler( - (Event) value, vcenterDB, vncDB); - handler.handle(); + Event anEvent = (Event)value; + printEvent(anEvent); + eventHandler.handle(anEvent); } else { if (value != null) { s_logger.info("\n Received unhandled property"); @@ -415,8 +418,8 @@ void handleChanges(ObjectUpdate oUpdate) throws Exception vmInfo.updatedGuestNics(nics, vncDB); } } + s_logger.info("Done processing property update"); } - s_logger.info("+++++++++++++Update Processing Complete +++++++++++++++++++++"); } public void start() { @@ -517,6 +520,7 @@ public void run() // When sync is run, it also does // addPort to vrouter agent for existing VMIs. try { + s_logger.info("+++++++++++++ Starting sync +++++++++++++++++++++"); vcenterDB.setReadTimeout(VCENTER_READ_TIMEOUT); MainDB.sync(vcenterDB, vncDB, VCenterMonitor.mode); syncNeeded = false; @@ -528,8 +532,10 @@ public void run() continue; } TaskWatchDog.stopMonitoring(this); + s_logger.info("+++++++++++++ Sync complete +++++++++++++++++++++"); } + s_logger.info("+++++++++++++ Waiting for events +++++++++++++++++++++"); try { WaitOptions wOpt = new WaitOptions(); @@ -588,19 +594,15 @@ public void run() } } - void printVmEvent(Object value) - { - VmEvent anEvent = (VmEvent) value; + public static void printEvent(Event event) { s_logger.info("\n----------" + "\n Event ID: " - + anEvent.getKey() + "\n Event: " - + anEvent.getClass().getName() - + "\n FullFormattedMessage: " - + anEvent.getFullFormattedMessage() - + "\n VM Reference: " - + anEvent.getVm().getVm().get_value() - + "\n createdTime : " - + anEvent.getCreatedTime().getTime() - + "\n----------\n"); + + event.getKey() + "\n Event: " + + event.getClass().getName() + + ", happened on: " + + event.getCreatedTime().getTime() + + "\n FullFormattedMessage: " + + event.getFullFormattedMessage() + + "\n----------\n"); } public static VncDB getVncDB() {