Hi,
I recently attempted to migrate my VXLAN transport zone to a new distributed virtual switch. Everything from the NSX Installation page looks good. The Controllers are all green, the Host Preparation tab looks (mostly) good (more on that in a second), and the VXLAN Transport and Transport Zones sections all look good as well.
The problem is that when I go to create a new Logical Switch, I get a vague response from the GUI after the task hits 0% in the recent tasks pane: "The last operation failed for the entity with the following error message. Internal server error has occurred."
The NSX Manager log file is much more detailed. It seems to me that there is something that NSX is looking for that is not registered, or something that is registered that NSX is not expecting. Any idea how I can resolve this? The only thing I'm suspecting is that perhaps the empty vSphere cluster that has no hosts configured for VXLAN (config status under VXLAN Transport is "Not Configured"), but I did not make that cluster part of the Transport Zone.
Here's the log file that contains the errors generated when I attempted to create a Logical Switch.
I HAVE rebooted the NSX Manager, but it didn't help.
2015-08-17 17:07:04.303 GMT INFO http-nio-127.0.0.1-7441-exec-1 UserSessionManager:43 - New session: XXXXXXXXXXXXXXXXXXXXXXXXXXXE7F76
2015-08-17 17:07:04.325 GMT INFO http-nio-127.0.0.1-7441-exec-1 VirtualWireServiceImpl:810 - Creating virtual wire for vdn scope:vdnscope-3
2015-08-17 17:07:04.338 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnIdManagerImpl:108 - getNextSegmentTx(virtual wire tenant,false)
2015-08-17 17:07:04.338 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnIdManagerImpl:123 - Multicast address not requested.
2015-08-17 17:07:04.339 GMT INFO http-nio-127.0.0.1-7441-exec-1 ResourceDao:309 - getNextResource(1)
2015-08-17 17:07:04.340 GMT INFO http-nio-127.0.0.1-7441-exec-1 ResourceDao:315 - Ranges for this resource type: "[5000 - 9999] "
2015-08-17 17:07:04.341 GMT INFO http-nio-127.0.0.1-7441-exec-1 ResourceDao:338 - Found an entry with least reference count.
2015-08-17 17:07:04.342 GMT INFO http-nio-127.0.0.1-7441-exec-1 ResourceDao:345 - existing entry ID: 2
2015-08-17 17:07:04.342 GMT INFO http-nio-127.0.0.1-7441-exec-1 ResourceDao:121 - adjustRefCount(2, 1)
2015-08-17 17:07:04.343 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnIdManagerImpl:129 - Next segment ID: 5000
2015-08-17 17:07:04.344 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnSegmentDao:101 - insert(virtual wire tenant, 5000, null)
2015-08-17 17:07:04.345 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnIdManagerImpl:136 - New segment DB ID: #11
2015-08-17 17:07:04.346 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnSegmentDao:231 - get(11)
2015-08-17 17:07:04.347 GMT INFO http-nio-127.0.0.1-7441-exec-1 VirtualWireServiceImpl:964 - next segment: vdnId: 5000, multicast: disabled
2015-08-17 17:07:04.364 GMT INFO http-nio-127.0.0.1-7441-exec-1 AuditingServiceImpl:143 - [AuditLog] UserName:'<redacted>', ModuleName:'VirtualWire', Operation:'CREATE', Resource:'testing', Time:'Mon Aug 17 17:07:04.361 GMT 2015'
2015-08-17 17:07:04.373 GMT INFO DCNPool-6 VirtualWireInFirewallRuleNotificationHandler:58 - Recieved VDN CREATE notification for context virtualwire-11:VirtualWire
2015-08-17 17:07:04.374 GMT INFO DCNPool-6 VirtualWireDCNHandler:43 - Recieved VDN CREATE notification for context virtualwire-11:VirtualWire
2015-08-17 17:07:04.382 GMT INFO http-nio-127.0.0.1-7441-exec-1 XvsServiceImpl:171 - createNetwork(dvs-81, vxw-dvs-81-virtualwire-11-sid-5000-testing)
2015-08-17 17:07:04.396 GMT INFO http-nio-127.0.0.1-7441-exec-1 DistributedVirtualSwitchVcOperationsImpl:116 - Adding portgroup vxw-dvs-81-virtualwire-11-sid-5000-testing
2015-08-17 17:07:04.450 GMT INFO ViInventoryThread ViInventory:5003 - Virtual Center: Updating Inventory. new:1 modified:0 removed:0
2015-08-17 17:07:04.465 GMT INFO ViInventoryThread EndpointSVMUpdater:206 - Solution 6341068275337691137 is not registered
2015-08-17 17:07:04.478 GMT INFO http-nio-127.0.0.1-7441-exec-1 DistributedVirtualSwitchVcOperationsImpl:123 - Add portgroup task completed on VC for vxw-dvs-81-virtualwire-11-sid-5000-testing : dvpgId dvportgroup-115
2015-08-17 17:07:04.479 GMT INFO http-nio-127.0.0.1-7441-exec-1 AbstractSubscribableChannel:69 - Channel 'vimDataChange' has 20 subscriber(s).
2015-08-17 17:07:04.482 GMT INFO ViInventoryThread ViInventory:1304 - 33/44 objects published.
2015-08-17 17:07:04.483 GMT INFO ViInventoryThread VimObjectBridge:952 - VimObjectBridge: Ending inventory update
2015-08-17 17:07:04.483 GMT INFO ViInventoryThread VimObjectBridge:223 - Processing 1 updates and 0 deletions for this transaction
2015-08-17 17:07:04.487 GMT INFO ViInventoryThread VimObjectBridge:230 - VimObjectBridge: Time taken to process transaction : 8
2015-08-17 17:07:04.487 GMT INFO ViInventoryThread ViInventory:1662 - cleared the deleted objects set
2015-08-17 17:07:04.488 GMT INFO ViInventoryThread ViInventory:1512 - Resolved, last version:863 num vc objs:37 num vimos:44
2015-08-17 17:07:04.569 GMT INFO ViInventoryThread ViInventory:5003 - Virtual Center: Updating Inventory. new:0 modified:10 removed:0
2015-08-17 17:07:04.584 GMT INFO ViInventoryThread EndpointSVMUpdater:206 - Solution 6341068275337691137 is not registered
2015-08-17 17:07:04.966 GMT INFO ViInventoryThread ViInventory:1304 - 35/44 objects published.
2015-08-17 17:07:04.987 GMT INFO ViInventoryThread VimObjectBridge:952 - VimObjectBridge: Ending inventory update
2015-08-17 17:07:04.988 GMT INFO ViInventoryThread VimObjectBridge:223 - Processing 10 updates and 0 deletions for this transaction
2015-08-17 17:07:04.994 GMT INFO ViInventoryThread VimObjectBridge:230 - VimObjectBridge: Time taken to process transaction : 395
2015-08-17 17:07:04.994 GMT INFO ViInventoryThread ViInventory:1662 - cleared the deleted objects set
2015-08-17 17:07:04.995 GMT INFO ViInventoryThread ViInventory:1512 - Resolved, last version:864 num vc objs:37 num vimos:44
2015-08-17 17:07:05.491 GMT INFO http-nio-127.0.0.1-7441-exec-1 DistributedVirtualSwitchVcOperationsImpl:127 - portgroup vxw-dvs-81-virtualwire-11-sid-5000-testing added to inventory successfully :: true
2015-08-17 17:07:05.491 GMT INFO http-nio-127.0.0.1-7441-exec-1 AbstractSubscribableChannel:69 - Channel 'vimDataChange' has 19 subscriber(s).
2015-08-17 17:07:05.492 GMT INFO http-nio-127.0.0.1-7441-exec-1 VcDriver:289 - Portgroup vxw-dvs-81-virtualwire-11-sid-5000-testing created successfuly
2015-08-17 17:07:05.497 GMT INFO http-nio-127.0.0.1-7441-exec-1 NetworkFeatureConfigUtil:188 - Added network feature NetworkFeature [objectId=virtualwire-11, featureName=ipDiscovery, featureStatus=enabled] in database.
2015-08-17 17:07:05.498 GMT INFO http-nio-127.0.0.1-7441-exec-1 NetworkFeatureConfigUtil:208 - Compiled OpaqueData featuresEnabled=ipDiscovery for Opaque Key dvfilter-generic-vmware-swsec.config for vWire virtualwire-11
2015-08-17 17:07:05.501 GMT INFO DCNPool-7 SIMessagingHelper:362 - Publishing 0 ServiceProfiles for DVPG :dvportgroup-115 (DVS:dvs-81 Datacenter:datacenter-21)
2015-08-17 17:07:05.565 GMT INFO http-nio-127.0.0.1-7441-exec-1 VcDriver:419 - vDN configured successfully on portgroup : vxw-dvs-81-virtualwire-11-sid-5000-testing
2015-08-17 17:07:05.614 GMT INFO http-nio-127.0.0.1-7441-exec-1 AuditingServiceImpl:143 - [AuditLog] UserName:'msp.lab\ericst', ModuleName:'VirtualWire', Operation:'MODIFY', Resource:'testing', Time:'Mon Aug 17 17:07:05.612 GMT 2015'
2015-08-17 17:07:05.627 GMT INFO http-nio-127.0.0.1-7441-exec-1 ControllerServiceImpl:1090 - create VNI: 5000 mcast=true
2015-08-17 17:07:05.651 GMT WARN http-nio-127.0.0.1-7441-exec-1 RestTemplate:478 - POST request for "https://172.22.58.84:443/ws.v1/lswitch" resulted in 404 (Not Found); invoking error handler
2015-08-17 17:07:05.652 GMT ERROR http-nio-127.0.0.1-7441-exec-1 NvpRestClientManagerImpl:602 - NVP API returns error: [404] Entity '5119009b-e2cb-46c8-83c8-2f80bef2715b' not registered.
2015-08-17 17:07:05.652 GMT ERROR http-nio-127.0.0.1-7441-exec-1 VirtualWireServiceImpl:878 - Failed to create virtualwire [vw_id : virtualwire-11, vni : 5000, lswitchuuid : null]
org.springframework.web.client.HttpClientErrorException: 404 Not Found
at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:75)
at org.springframework.web.client.RestTemplate.handleResponseError(RestTemplate.java:486)
at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:443)
at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:401)
at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:377)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClient.sendRequestOnce(NvpRestClient.java:300)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClient.sendRequestEx(NvpRestClient.java:268)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClientManagerImpl.sendRequestExWithRetry(NvpRestClientManagerImpl.java:585)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClientManagerImpl.sendRequestEx(NvpRestClientManagerImpl.java:537)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClientManagerImpl.sendRequest(NvpRestClientManagerImpl.java:522)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NVPVxlanApiImpl.createVNI(NVPVxlanApiImpl.java:78)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.ControllerServiceImpl.createVNI(ControllerServiceImpl.java:1100)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.createLSwitch(VirtualWireServiceImpl.java:975)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.createLSwitch_DiscardOnConflict(VirtualWireServiceImpl.java:986)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.create_aroundBody10(VirtualWireServiceImpl.java:866)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl$AjcClosure11.run(VirtualWireServiceImpl.java:1)
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at com.vmware.vshield.vsm.aspects.licensing.VsmLicensedAspect.checkLicense(VsmLicensedAspect.java:83)
at com.vmware.vshield.vsm.aspects.licensing.VsmLicensedAspect.ajc$inlineAccessMethod$com_vmware_vshield_vsm_aspects_licensing_VsmLicensedAspect$com_vmware_vshield_vsm_aspects_licensing_VsmLicensedAspect$checkLicense(VsmLicensedAspect.java:1)
at com.vmware.vshield.vsm.aspects.licensing.VsmLicensedAspect.licenseCheck(VsmLicensedAspect.java:50)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.create_aroundBody12(VirtualWireServiceImpl.java:803)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl$AjcClosure13.run(VirtualWireServiceImpl.java:1)
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at com.vmware.vshield.vsm.aspects.security.VsmSecuredAspect.secureCheck(VsmSecuredAspect.java:105)
at com.vmware.vshield.vsm.aspects.security.VsmSecuredAspect.ajc$inlineAccessMethod$com_vmware_vshield_vsm_aspects_security_VsmSecuredAspect$com_vmware_vshield_vsm_aspects_security_VsmSecuredAspect$secureCheck(VsmSecuredAspect.java:1)
at com.vmware.vshield.vsm.aspects.security.VsmSecuredAspect.secure(VsmSecuredAspect.java:58)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.create(VirtualWireServiceImpl.java:803)
at com.vmware.vshield.vsm.vdn.facade.VirtualWireFacadeImpl.create(VirtualWireFacadeImpl.java:61)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.remoting.support.RemoteInvocationTraceInterceptor.invoke(RemoteInvocationTraceInterceptor.java:77)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy386.create(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.remoting.support.RemoteInvocation.invoke(RemoteInvocation.java:205)
at org.springframework.remoting.support.DefaultRemoteInvocationExecutor.invoke(DefaultRemoteInvocationExecutor.java:38)
at org.springframework.remoting.support.RemoteInvocationBasedExporter.invoke(RemoteInvocationBasedExporter.java:78)
at org.springframework.remoting.support.RemoteInvocationBasedExporter.invokeAndCreateResult(RemoteInvocationBasedExporter.java:114)
at org.springframework.remoting.httpinvoker.HttpInvokerServiceExporter.handleRequest(HttpInvokerServiceExporter.java:73)
at org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter.handle(HttpRequestHandlerAdapter.java:49)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:790)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:719)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:669)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:585)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:646)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:369)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:109)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:97)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:100)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:78)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:35)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at com.vmware.vshield.vsm.security.utils.VsmSSOBasicAuthenticationFilter.doFilter(VsmSSOBasicAuthenticationFilter.java:200)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.preauth.AbstractPreAuthenticatedProcessingFilter.doFilter(AbstractPreAuthenticatedProcessingFilter.java:89)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:79)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:109)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:168)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at com.bluelane.em.filter.GenericOperationsOnRequestFilter.doFilter(GenericOperationsOnRequestFilter.java:97)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1736)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1695)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Unknown Source)
2015-08-17 17:07:05.677 GMT INFO http-nio-127.0.0.1-7441-exec-1 XvsServiceImpl:185 - deleteNetwork(dvs-81, dvportgroup-115)
2015-08-17 17:07:05.715 GMT INFO DCNPool-8 VirtualWireInFirewallRuleNotificationHandler:58 - Recieved VDN MODIFY notification for context virtualwire-11:VirtualWire
2015-08-17 17:07:05.726 GMT INFO DCNPool-8 VirtualWireDCNHandler:43 - Recieved VDN MODIFY notification for context virtualwire-11:VirtualWire
2015-08-17 17:07:05.738 GMT INFO DCNPool-5 SIMessagingHelper:362 - Publishing 0 ServiceProfiles for DVPG :dvportgroup-115 (DVS:dvs-81 Datacenter:datacenter-21)
2015-08-17 17:07:05.793 GMT INFO ViInventoryThread ViInventory:5003 - Virtual Center: Updating Inventory. new:0 modified:1 removed:0
2015-08-17 17:07:05.808 GMT INFO ViInventoryThread EndpointSVMUpdater:206 - Solution 6341068275337691137 is not registered
2015-08-17 17:07:05.829 GMT INFO ViInventoryThread ViInventory:1304 - 35/44 objects published.
2015-08-17 17:07:05.829 GMT INFO ViInventoryThread VimObjectBridge:952 - VimObjectBridge: Ending inventory update
2015-08-17 17:07:05.829 GMT INFO ViInventoryThread VimObjectBridge:223 - Processing 1 updates and 0 deletions for this transaction
2015-08-17 17:07:05.830 GMT INFO ViInventoryThread VimObjectBridge:230 - VimObjectBridge: Time taken to process transaction : 6
2015-08-17 17:07:05.830 GMT INFO ViInventoryThread ViInventory:1662 - cleared the deleted objects set
2015-08-17 17:07:05.831 GMT INFO ViInventoryThread ViInventory:1512 - Resolved, last version:865 num vc objs:37 num vimos:44
2015-08-17 17:07:05.888 GMT INFO http-nio-127.0.0.1-7441-exec-1 VcDriver:753 - Portgroup dvportgroup-115 deleted successfuly
2015-08-17 17:07:05.903 GMT INFO http-nio-127.0.0.1-7441-exec-1 VirtualWireServiceImpl:790 - Deleting virtual wire with id virtualwire-11, segment vlan id 5000
2015-08-17 17:07:05.914 GMT INFO ViInventoryThread ViInventory:5003 - Virtual Center: Updating Inventory. new:0 modified:9 removed:1
2015-08-17 17:07:05.930 GMT INFO ViInventoryThread EndpointSVMUpdater:206 - Solution 6341068275337691137 is not registered
2015-08-17 17:07:05.974 GMT INFO ViInventoryThread ViInventory:1304 - 33/43 objects published.
2015-08-17 17:07:06.071 GMT INFO http-nio-127.0.0.1-7441-exec-1 AuditingServiceImpl:143 - [AuditLog] UserName:'msp.lab\ericst', ModuleName:'VirtualWire', Operation:'DELETE', Resource:'testing', Time:'Mon Aug 17 17:07:06.064 GMT 2015'
2015-08-17 17:07:06.072 GMT INFO http-nio-127.0.0.1-7441-exec-1 VirtualWireServiceImpl:792 - Deleted virtual wire with id virtualwire-11, segment vlan id 5000
2015-08-17 17:07:06.073 GMT INFO http-nio-127.0.0.1-7441-exec-1 VirtualWireServiceImpl:794 - Releasing segment with VdnId 5000
2015-08-17 17:07:06.073 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnIdManagerImpl:189 - releaseVdnIdTx(5000)
2015-08-17 17:07:06.075 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnIdManagerImpl:205 - Released VDN ID: 5000 (#2)
2015-08-17 17:07:06.076 GMT INFO http-nio-127.0.0.1-7441-exec-1 VdnIdManagerImpl:209 - Remove VDN segment: #11
2015-08-17 17:07:06.076 GMT INFO http-nio-127.0.0.1-7441-exec-1 VirtualWireServiceImpl:796 - Released segment with VdnId 5000
2015-08-17 17:07:06.081 GMT WARN http-nio-127.0.0.1-7441-exec-1 RemoteInvocationTraceInterceptor:87 - Processing of VsmHttpInvokerServiceExporter remote call resulted in fatal exception: com.vmware.vshield.vsm.vdn.facade.VirtualWireFacade.create
org.springframework.web.client.HttpClientErrorException: 404 Not Found
at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:75)
at org.springframework.web.client.RestTemplate.handleResponseError(RestTemplate.java:486)
at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:443)
at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:401)
at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:377)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClient.sendRequestOnce(NvpRestClient.java:300)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClient.sendRequestEx(NvpRestClient.java:268)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClientManagerImpl.sendRequestExWithRetry(NvpRestClientManagerImpl.java:585)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClientManagerImpl.sendRequestEx(NvpRestClientManagerImpl.java:537)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NvpRestClientManagerImpl.sendRequest(NvpRestClientManagerImpl.java:522)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.NVPVxlanApiImpl.createVNI(NVPVxlanApiImpl.java:78)
at com.vmware.vshield.vsm.vdn.nvpcontroller.service.impl.ControllerServiceImpl.createVNI(ControllerServiceImpl.java:1100)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.createLSwitch(VirtualWireServiceImpl.java:975)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.createLSwitch_DiscardOnConflict(VirtualWireServiceImpl.java:986)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.create_aroundBody10(VirtualWireServiceImpl.java:866)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl$AjcClosure11.run(VirtualWireServiceImpl.java:1)
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at com.vmware.vshield.vsm.aspects.licensing.VsmLicensedAspect.checkLicense(VsmLicensedAspect.java:83)
at com.vmware.vshield.vsm.aspects.licensing.VsmLicensedAspect.ajc$inlineAccessMethod$com_vmware_vshield_vsm_aspects_licensing_VsmLicensedAspect$com_vmware_vshield_vsm_aspects_licensing_VsmLicensedAspect$checkLicense(VsmLicensedAspect.java:1)
at com.vmware.vshield.vsm.aspects.licensing.VsmLicensedAspect.licenseCheck(VsmLicensedAspect.java:50)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.create_aroundBody12(VirtualWireServiceImpl.java:803)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl$AjcClosure13.run(VirtualWireServiceImpl.java:1)
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at com.vmware.vshield.vsm.aspects.security.VsmSecuredAspect.secureCheck(VsmSecuredAspect.java:105)
at com.vmware.vshield.vsm.aspects.security.VsmSecuredAspect.ajc$inlineAccessMethod$com_vmware_vshield_vsm_aspects_security_VsmSecuredAspect$com_vmware_vshield_vsm_aspects_security_VsmSecuredAspect$secureCheck(VsmSecuredAspect.java:1)
at com.vmware.vshield.vsm.aspects.security.VsmSecuredAspect.secure(VsmSecuredAspect.java:58)
at com.vmware.vshield.vsm.vdn.service.VirtualWireServiceImpl.create(VirtualWireServiceImpl.java:803)
at com.vmware.vshield.vsm.vdn.facade.VirtualWireFacadeImpl.create(VirtualWireFacadeImpl.java:61)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.remoting.support.RemoteInvocationTraceInterceptor.invoke(RemoteInvocationTraceInterceptor.java:77)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy386.create(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.remoting.support.RemoteInvocation.invoke(RemoteInvocation.java:205)
at org.springframework.remoting.support.DefaultRemoteInvocationExecutor.invoke(DefaultRemoteInvocationExecutor.java:38)
at org.springframework.remoting.support.RemoteInvocationBasedExporter.invoke(RemoteInvocationBasedExporter.java:78)
at org.springframework.remoting.support.RemoteInvocationBasedExporter.invokeAndCreateResult(RemoteInvocationBasedExporter.java:114)
at org.springframework.remoting.httpinvoker.HttpInvokerServiceExporter.handleRequest(HttpInvokerServiceExporter.java:73)
at org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter.handle(HttpRequestHandlerAdapter.java:49)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:790)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:719)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:669)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:585)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:646)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:369)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:109)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:97)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:100)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:78)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:35)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at com.vmware.vshield.vsm.security.utils.VsmSSOBasicAuthenticationFilter.doFilter(VsmSSOBasicAuthenticationFilter.java:200)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.preauth.AbstractPreAuthenticatedProcessingFilter.doFilter(AbstractPreAuthenticatedProcessingFilter.java:89)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:79)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:109)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:381)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:168)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:237)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:167)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at com.bluelane.em.filter.GenericOperationsOnRequestFilter.doFilter(GenericOperationsOnRequestFilter.java:97)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1736)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1695)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Unknown Source)
2015-08-17 17:07:06.088 GMT INFO DCNPool-1 VirtualWireInFirewallRuleNotificationHandler:58 - Recieved VDN DELETE notification for context virtualwire-11:VirtualWire
2015-08-17 17:07:06.093 GMT INFO DCNPool-1 FirewallDao:568 - source virtualwire-11 used in firewall rules 0
2015-08-17 17:07:06.096 GMT INFO DCNPool-1 FirewallDao:578 - Destination virtualwire-11 used in firewall rules 0
2015-08-17 17:07:06.097 GMT INFO DCNPool-1 VirtualWireDCNHandler:43 - Recieved VDN DELETE notification for context virtualwire-11:VirtualWire
2015-08-17 17:07:06.104 GMT INFO DCNPool-3 SIMessagingHelper:362 - Publishing 0 ServiceProfiles for DVPG :dvportgroup-115 (DVS:dvs-81 Datacenter:datacenter-21)
2015-08-17 17:07:06.344 GMT INFO ViInventoryThread VimObjectBridge:952 - VimObjectBridge: Ending inventory update
2015-08-17 17:07:06.344 GMT INFO ViInventoryThread VimObjectBridge:223 - Processing 9 updates and 0 deletions for this transaction
2015-08-17 17:07:06.348 GMT ERROR ViInventoryThread BatchingBatcher:73 - Exception executing batch:
org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:85)
at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70)
at org.hibernate.jdbc.BatchingBatcher.checkRowCounts(BatchingBatcher.java:90)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:114)
at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:109)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2658)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2895)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:97)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:267)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:259)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:183)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1206)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:375)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137)
at org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:76)
at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:467)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge$TransactionBinding.commit(VimObjectBridge.java:134)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge$TransactionBinding.access$4(VimObjectBridge.java:133)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge.closeTransaction(VimObjectBridge.java:228)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge.endUpdates(VimObjectBridge.java:953)
at com.bluelane.vfc.inventory.ViInventoryBridge.publishEndUpdates(ViInventoryBridge.java:1319)
at com.bluelane.vfc.inventory.ViInventory.sendUpdatesOverBridge(ViInventory.java:1653)
at com.bluelane.vfc.inventory.ViInventory.sendUpdates(ViInventory.java:1594)
at com.bluelane.vfc.inventory.ViInventory.attemptResolveMORefs(ViInventory.java:1216)
at com.bluelane.vfc.inventory.ViInventory.waitOnce(ViInventory.java:1509)
at com.bluelane.vfc.inventory.ViInventoryThread.waitForInventoryChangeEvents(ViInventoryThread.java:61)
at com.bluelane.vfc.inventory.ViInventoryThread.run(ViInventoryThread.java:51)
2015-08-17 17:07:06.349 GMT ERROR ViInventoryThread AbstractFlushingEventListener:324 - Could not synchronize database state with session
org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:85)
at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70)
at org.hibernate.jdbc.BatchingBatcher.checkRowCounts(BatchingBatcher.java:90)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:114)
at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:109)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2658)
at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2895)
at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:97)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:267)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:259)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:183)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1206)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:375)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137)
at org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:76)
at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:467)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge$TransactionBinding.commit(VimObjectBridge.java:134)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge$TransactionBinding.access$4(VimObjectBridge.java:133)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge.closeTransaction(VimObjectBridge.java:228)
at com.vmware.vshield.vsm.inventory.service.impl.VimObjectBridge.endUpdates(VimObjectBridge.java:953)
at com.bluelane.vfc.inventory.ViInventoryBridge.publishEndUpdates(ViInventoryBridge.java:1319)
at com.bluelane.vfc.inventory.ViInventory.sendUpdatesOverBridge(ViInventory.java:1653)
at com.bluelane.vfc.inventory.ViInventory.sendUpdates(ViInventory.java:1594)
at com.bluelane.vfc.inventory.ViInventory.attemptResolveMORefs(ViInventory.java:1216)
at com.bluelane.vfc.inventory.ViInventory.waitOnce(ViInventory.java:1509)
at com.bluelane.vfc.inventory.ViInventoryThread.waitForInventoryChangeEvents(ViInventoryThread.java:61)
at com.bluelane.vfc.inventory.ViInventoryThread.run(ViInventoryThread.java:51)
2015-08-17 17:07:06.353 GMT INFO ViInventoryThread ViInventory:1598 - Caught org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1 on attempt #1
2015-08-17 17:07:06.383 GMT INFO ViInventoryThread ViInventory:1304 - 33/43 objects published.
2015-08-17 17:07:06.721 GMT INFO ViInventoryThread VimObjectBridge:952 - VimObjectBridge: Ending inventory update
2015-08-17 17:07:06.721 GMT INFO ViInventoryThread VimObjectBridge:223 - Processing 9 updates and 0 deletions for this transaction
2015-08-17 17:07:06.732 GMT INFO ViInventoryThread VimObjectBridge:230 - VimObjectBridge: Time taken to process transaction : 377
2015-08-17 17:07:06.732 GMT INFO ViInventoryThread ViInventory:1662 - cleared the deleted objects set
2015-08-17 17:07:06.733 GMT INFO ViInventoryThread ViInventory:1512 - Resolved, last version:866 num vc objs:36 num vimos:43
2015-08-17 17:07:07.083 GMT INFO DCNPool-6 FirewallDao:568 - source dvportgroup-115 used in firewall rules 0
2015-08-17 17:07:07.086 GMT INFO DCNPool-6 FirewallDao:578 - Destination dvportgroup-115 used in firewall rules 0
2015-08-17 17:07:07.091 GMT INFO DCNPool-6 FirewallDao:586 - AppliedTo dvportgroup-115 used in firewall rules 0
2015-08-17 17:07:49.671 GMT ERROR HeartbeatManagerHeartbeatTimer HeartbeatManager$HeartbeatTask:297 - Client has not responded to the heartbeat for longer than the alert threshold. Peer name = 'com.vmware.vshield.userworld', client token = 'host-49', client id = 'f2939a1d-4c1c-40cb-9904-9b497fd9c4b8', last heartbeat response = '0', last published heartbeat = '1366'
2015-08-17 17:07:49.674 GMT WARN HeartbeatManagerHeartbeatTimer MessagingInfraMessageHandler:71 - Received a heartbeat alert for host-49 even though the feature is not installed.
2015-08-17 17:07:49.682 GMT INFO HeartbeatManagerHeartbeatTimer SystemEventDaoImpl:128 - [SystemEvent] Time:'Mon Aug 17 17:07:49.675 GMT 2015', Severity:'Critical', Event Source:'Host messaging infrastructure', Code:'391002', Event Message:'Messaging infrastructure down on host.', Module:'Messaging infrastructure.'
2015-08-17 17:07:49.693 GMT ERROR HeartbeatManagerHeartbeatTimer ResponseHandler:116 - Unable to find host for client id: f2939a1d-4c1c-40cb-9904-9b497fd9c4b8
2015-08-17 17:07:49.698 GMT ERROR HeartbeatManagerHeartbeatTimer ResponseHandler:116 - Unable to find host for client id: f2939a1d-4c1c-40cb-9904-9b497fd9c4b8
2015-08-17 17:07:52.105 GMT INFO edgeVseMonitoringThread EdgeVseHealthMonitoringThread:219 - Finished Health check for 0 edge vms in 0 sec
Are you familiar with managing NSX via the REST API? Run this via the REST API to force remove.
DELETE https:/172.22.58.74/api/2.0/vdn/controller/controller-16?forceRemoval=true
Assuming 172.22.58.74 is the IP of NSX Manager, and Controller-16 is the name of the controller.
Once that is complete, migrate the transport zone to a multicast mode. Then, redeploy the controllers. Once complete, migrate the transport zone back to Unicast Mode. Then, try to create a logical switch.
Do you have any existing logical switches configured in this environment?
Do you have 3 controllers deployed? Could you post the results for these commands on all 3 controllers?
show control-cluster connections
show control-cluster status
No logical switches in the environment at all right now. I did deploy one logical switch initially when using the old DVS, but I deleted it prior to moving to the new DVS.
Yes, I do have three controllers deployed. Here's the output you requested from all three.
Controller 1
htb-1n-eng-dhcp10 # show control-cluster connections
role port listening open conns
--------------------------------------------------------
api_provider api/443 Y 1
--------------------------------------------------------
persistence_server server/2878 - 0
client/2888 Y 0
election/3888 Y 0
--------------------------------------------------------
switch_manager ovsmgmt/6632 Y 0
openflow/6633 Y 0
--------------------------------------------------------
system cluster/7777 Y 0
htb-1n-eng-dhcp10 # show control-cluster status
Type Status Since
--------------------------------------------------------------------------------
Join status: Join complete 08/14 17:07:10
Majority status: Connected to cluster majority 08/16 09:09:33
Restart status: This controller can be safely restarted 08/16 09:08:13
Cluster ID: 90509f7a-a441-4930-9c11-ef2b54ea27fd
Node UUID: 90509f7a-a441-4930-9c11-ef2b54ea27fd
Role Configured status Active status
--------------------------------------------------------------------------------
api_provider enabled activated
persistence_server enabled activated
switch_manager enabled activated
logical_manager enabled activated
directory_server enabled activated
Controller 2
htb-1n-eng-dhcp10 # show control-cluster connections
role port listening open conns
--------------------------------------------------------
api_provider api/443 Y 2
--------------------------------------------------------
persistence_server server/2878 Y 2
client/2888 Y 2
election/3888 Y 0
--------------------------------------------------------
switch_manager ovsmgmt/6632 Y 0
openflow/6633 Y 0
--------------------------------------------------------
system cluster/7777 Y 1
htb-1n-eng-dhcp10 # show control-cluster status
Type Status Since
--------------------------------------------------------------------------------
Join status: Join complete 08/14 20:19:05
Majority status: Connected to cluster majority 08/16 09:09:34
Restart status: This controller can be safely restarted 08/16 09:08:34
Cluster ID: 90509f7a-a441-4930-9c11-ef2b54ea27fd
Node UUID: 04d83afa-0669-4c8d-a40b-8e6dc9c7ea32
Role Configured status Active status
--------------------------------------------------------------------------------
api_provider enabled activated
persistence_server enabled activated
switch_manager enabled activated
logical_manager enabled activated
directory_server enabled activated
Controller 3
htb-1n-eng-dhcp10 # show control-cluster connections
role port listening open conns
--------------------------------------------------------
api_provider api/443 Y 2
--------------------------------------------------------
persistence_server server/2878 - 0
client/2888 Y 1
election/3888 Y 0
--------------------------------------------------------
switch_manager ovsmgmt/6632 Y 0
openflow/6633 Y 0
--------------------------------------------------------
system cluster/7777 Y 1
htb-1n-eng-dhcp10 # show control-cluster status
Type Status Since
--------------------------------------------------------------------------------
Join status: Join complete 08/14 20:27:23
Majority status: Connected to cluster majority 08/16 09:08:13
Restart status: This controller can be safely restarted 08/16 09:08:13
Cluster ID: 90509f7a-a441-4930-9c11-ef2b54ea27fd
Node UUID: ed163711-faf0-4225-a574-d6478cf244af
Role Configured status Active status
--------------------------------------------------------------------------------
api_provider enabled activated
persistence_server enabled activated
switch_manager enabled activated
logical_manager enabled activated
directory_server enabled activated
Log into your NSX Manager and make sure all your components are running, and then reboot all your controllers. I had the same issue, and my controllers were 'disconnected' and NSX management services were not running, and once I fixed that, I was able to resolve the issue.
Thanks for the reply. Unfortunately rebooting both NSX Manager and all three controllers did not work. I waited for NSX Manager to come up completely before rebooting the controllers. I still get the same error as before.
From the controller, you can run the command show network connections of-type tcp which will produce a list of network connections. In that list you should see connections to the NSX Manager. If not, there is a problem.
How many connections to the NSX Manager should I see from each controller? The IP ending in .74 is my NSX Manager.
I see one connection from "controller 1" to the NSX Manager on port 51452.
tcp 0 0 172.x.x.75:443 172.x.x.74:51452 ESTABLISHED 1085/python
I see two connections from "controller 2" to the NSX Manager. One on port 52644 and one on port 32807.
tcp 0 0 172.x.x.76:443 172.x.x.74:52644 ESTABLISHED 1082/python
tcp 0 0 172.x.x.76:443 172.x.x.74:32807 ESTABLISHED 1082/python
I see one connection from "controller 3" to the NSX Manager on port 53526.
tcp 0 0 172.x.x.84:443 172.x.x.74:53526 ESTABLISHED 1075/python
I just tried to create the Logical Switch using the SSO Administrator account. It failed the same as before, but this time I caught some tasks in the Recent Tasks pane. The distributed port group gets created, but 2 seconds later it gets deleted.
All of my controllers have 4 connections to the manager. What version of NSX have you deployed? Did you go through with the migration to a new dvSwitch? If you haven't done so already, there may be some benefit in removing the transport zone, unconfiguring the cluster (in the VXLAN Transport section), and then reconfiguring the VXLAN Transport and re-creating the transport zone.
Based on the log you provided in the initial post, I was able to see the dvPortGroup being created and deleted.
NSX 6.1.41894. I took your advice and re-creating the transport zone after unconfiguring the cluster and reconfiguring VXLAN. Unfortunately it didn't help. I'm now strongly considering starting from scratch, but was hoping that it was something more obvious.
The next step would be redeploying fresh controllers. The log does show some issues between NSX Manager and the controller with the IP 172.22.58.84. Once the dvPortGroup is created, NSX Manager tells the Control Cluster about the new logical switch and that's about it. That seems to be where it's failing.
WARN http-nio-127.0.0.1-7441-exec-1 RestTemplate:478 - POST request for "https://172.22.58.84/ws.v1/lswitchhttps://172.22.58.84:443/ws.v1/lswitch" resulted in 404 (Not Found); invoking error handler
OK. I noticed I can't delete all three and start over, so I will need to delete the first two, deploy two new ones, and then delete and deploy the last one, correct? Is there any other way to recreate the NSX controller cluster?
Are you getting an error when trying to delete the last of the 3 controllers?
Yes. It won't let me delete the last controller. The specific message is "Failed to remove controller controller-16 - last controller being removed, need specify forceRemoval."
Are you familiar with managing NSX via the REST API? Run this via the REST API to force remove.
DELETE https:/172.22.58.74/api/2.0/vdn/controller/controller-16?forceRemoval=true
Assuming 172.22.58.74 is the IP of NSX Manager, and Controller-16 is the name of the controller.
Once that is complete, migrate the transport zone to a multicast mode. Then, redeploy the controllers. Once complete, migrate the transport zone back to Unicast Mode. Then, try to create a logical switch.
The REST API force removal was successful.
I had already removed the transport zone previously, so there was no need to migrate it to multicast mode. I deployed three fresh controllers, configured VXLAN and setup the transport zone, and successfully created a new logical switch. Thanks so much for the assistance. The error messages were pretty vague so I was struggling to resolve this issue. There must have been something in the previous controller cluster configuration that wasn't correct after moving to the new distributed virtual switch.