Bug 968150 - [rhevm] Query GetDeviceListQuery failed. Exception message is VdcBLLException: Vds with id: <host_id> was not found
[rhevm] Query GetDeviceListQuery failed. Exception message is VdcBLLException...
Status: CLOSED INSUFFICIENT_DATA
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine (Show other bugs)
3.2.0
x86_64 Linux
unspecified Severity urgent
: ---
: 3.2.2
Assigned To: Yair Zaslavsky
vvyazmin@redhat.com
infra
: Triaged
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-05-29 01:58 EDT by vvyazmin@redhat.com
Modified: 2016-02-10 14:06 EST (History)
15 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-07-08 08:10:37 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Infra
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
## Logs rhevm, vdsm, libvirt, thread dump, vds_table (1.72 MB, application/x-gzip)
2013-05-29 01:58 EDT, vvyazmin@redhat.com
no flags Details
## Logs rhevm (41.10 MB, application/x-gzip)
2013-05-29 09:12 EDT, vvyazmin@redhat.com
no flags Details
## Logs rhevm server log (598.00 KB, application/x-gzip)
2013-05-30 03:58 EDT, vvyazmin@redhat.com
no flags Details

  None (edit)
Description vvyazmin@redhat.com 2013-05-29 01:58:32 EDT
Created attachment 754179 [details]
## Logs rhevm, vdsm, libvirt, thread dump, vds_table

Description of problem:
Query GetDeviceListQuery failed. Exception message is VdcBLLException: Vds with id: <host_id> was not found

Version-Release number of selected component (if applicable):
RHEVM 3.2 - SF17.1 environment: 

RHEVM: rhevm-3.2.0-11.28.el6ev.noarch 
VDSM: vdsm-4.10.2-21.0.el6ev.x86_64 
LIBVIRT: libvirt-0.10.2-18.el6_4.5.x86_64 
QEMU & KVM: qemu-kvm-rhev-0.12.1.2-2.355.el6_4.3.x86_64 
SANLOCK: sanlock-2.6-2.el6.x86_64

How reproducible:
unknow

Steps to Reproduce:
1. Create iSCSI DC with 50 hosts (in my case 50 fake hosts)
2. Try to add first Storage Domain
  
Actual results:
Failed create first Storage Domain

Expected results:
Succeed create first Storage Domain

Impact on user:
Can't create first Storage Domain

Workaround:
Reboot all RHEVM server (“service ovirt-engine restart” - not help)!

Additional info:

/var/log/ovirt-engine/engine.log

2013-05-28 18:11:33,583 ERROR [org.ovirt.engine.core.vdsbroker.ResourceManager] (ajp-/127.0.0.1:8702-7) Cannot get vdsManager for vdsid=e078d7ac-279d-49b3-898b-48df88d4a923
2013-05-28 18:11:33,583 ERROR [org.ovirt.engine.core.vdsbroker.ResourceManager] (ajp-/127.0.0.1:8702-7) CreateCommand failed: org.ovirt.engine.core.common.errors.VdcBLLException: VdcBLLException: V
ds with id: e078d7ac-279d-49b3-898b-48df88d4a923 was not found
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.initializeVdsBroker(VdsBrokerCommand.java:50) [engine-vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.<init>(VdsBrokerCommand.java:29) [engine-vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.GetDeviceListVDSCommand.<init>(GetDeviceListVDSCommand.java:32) [engine-vdsbroker.jar:]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) [rt.jar:1.7.0_19]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) [rt.jar:1.7.0_19]
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) [rt.jar:1.7.0_19]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:525) [rt.jar:1.7.0_19]
        at org.ovirt.engine.core.vdsbroker.ResourceManager.CreateCommand(ResourceManager.java:333) [engine-vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:370) [engine-vdsbroker.jar:]
        at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.RunVdsCommand(VDSBrokerFrontendImpl.java:33) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.storage.GetDeviceListQuery.executeQueryCommand(GetDeviceListQuery.java:35) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.QueriesCommandBase.ExecuteCommand(QueriesCommandBase.java:72) [engine-bll.jar:]
        at org.ovirt.engine.core.dal.VdcCommandBase.Execute(VdcCommandBase.java:28) [engine-dal.jar:]
        at org.ovirt.engine.core.bll.Backend.runQueryImpl(Backend.java:413) [engine-bll.jar:]
        at org.ovirt.engine.core.bll.Backend.RunQuery(Backend.java:390) [engine-bll.jar:]
        at sun.reflect.GeneratedMethodAccessor21.invoke(Unknown Source) [:1.7.0_19]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_19]
        at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_19]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee.jar:
7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.ovirt.engine.core.utils.ThreadLocalSessionCleanerInterceptor.injectWebContextToThreadLocal(ThreadLocalSessionCleanerInterceptor.java:11) [engine-utils.jar:]
        at sun.reflect.GeneratedMethodAccessor20.invoke(Unknown Source) [:1.7.0_19]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_19]
        at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_19]
        at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptorFactory$ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptorFactory.java:123) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:52) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:235) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:374) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:218) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2]
        at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee.jar:7.2.0.Final-redhat-8]
        at org.ovirt.engine.core.common.interfaces.BackendLocal$$$view8.RunQuery(Unknown Source) [engine-common.jar:]
        at org.ovirt.engine.ui.frontend.server.gwt.GenericApiGWTServiceImpl.RunQuery(GenericApiGWTServiceImpl.java:59)
        at sun.reflect.GeneratedMethodAccessor26.invoke(Unknown Source) [:1.7.0_19]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_19]
        at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_19]
        at com.google.gwt.rpc.server.RPC.invokeAndStreamResponse(RPC.java:196)
        at com.google.gwt.rpc.server.RpcServlet.processCall(RpcServlet.java:161)
        at com.google.gwt.rpc.server.RpcServlet.processPost(RpcServlet.java:222)
        at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:754) [jboss-servlet-api_3.0_spec.jar:1.0.2.Final-redhat-1]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [jboss-servlet-api_3.0_spec.jar:1.0.2.Final-redhat-1]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:295)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
        at org.ovirt.engine.ui.frontend.server.gwt.GwtCachingFilter.doFilter(GwtCachingFilter.java:132)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:246)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:149)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:481)
        at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:145)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
        at org.jboss.web.rewrite.RewriteValve.invoke(RewriteValve.java:465)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:336)
        at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:488)
        at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:420)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:920)
        at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_19]

2013-05-28 18:11:33,590 ERROR [org.ovirt.engine.core.bll.storage.GetDeviceListQuery] (ajp-/127.0.0.1:8702-7) Query GetDeviceListQuery failed. Exception message is VdcBLLException: Vds with id: e078d7ac-279d-49b3-898b-48df88d4a923 was not found

/var/log/vdsm/vdsm.log
Comment 1 Allon Mureinik 2013-05-29 04:53:35 EDT
The issue does not seem related to creating the new domain - engine cannot even send a command to VDSM:
<snip>
org.ovirt.engine.core.common.errors.VdcBLLException: VdcBLLException: V
ds with id: e078d7ac-279d-49b3-898b-48df88d4a923 was not found
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.initializeVdsBroker(VdsBrokerCommand.java:50) [engine-vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.<init>(VdsBrokerCommand.java:29) [engine-vdsbroker.jar:]
</snip>

Yair, any insight?
Comment 3 Yair Zaslavsky 2013-05-29 05:22:53 EDT
(In reply to Allon Mureinik from comment #1)
> The issue does not seem related to creating the new domain - engine cannot
> even send a command to VDSM:
> <snip>
> org.ovirt.engine.core.common.errors.VdcBLLException: VdcBLLException: V
> ds with id: e078d7ac-279d-49b3-898b-48df88d4a923 was not found
>         at
> org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.
> initializeVdsBroker(VdsBrokerCommand.java:50) [engine-vdsbroker.jar:]
>         at
> org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.
> <init>(VdsBrokerCommand.java:29) [engine-vdsbroker.jar:]
> </snip>
> 
> Yair, any insight?

As Allon stated, engine cannot create a new storage domain.
The problem is that ResouceManager which has a map from vds id to VdsManager does not have an entry for the relevant Host.
This of course can happen when the host is removed from the map, but this is not the case.

However, I have a feeling that in this scale test we are not removing any host. The problem can reside in the code that adds the host to the ResourceManager.

Vlad, can you please explain how the scale test was run? 
How many hosts you are adding? at what point do you start to try adding the storage domains? Do you wait for all the hosts to be added or not?

Thanks
Comment 4 vvyazmin@redhat.com 2013-05-29 09:09:35 EDT
Attached relevant log with AddVds Command, from vds id: e078d7ac-279d-49b3-898b-48df88d4a923

xzgrep e078d7ac-279d-49b3-898b-48df88d4a923 /var/log/ovirt-engine/engine.log*.xz | less -S

/var/log/ovirt-engine/engine.log.3-20130528_034102_7492.xz:2013-05-27 14:49:05,539 INFO  [org.ovirt.engine.core.bll.AddVdsSpmIdCommand] (ajp-/127.0.0.1:8702-16) [77b0c062] Runni
ng command: AddVdsSpmIdCommand internal: true. Entities affected : ID: e078d7ac-279d-49b3-898b-48df88d4a923 Type: VDS

Steps to Reproduce:
1. Create iSCSI DC with 50 hosts (in my case 50 fake hosts)
2. After I added all 50 hosts, and they have status UP, I try to add first Storage Domain
Comment 5 vvyazmin@redhat.com 2013-05-29 09:12:27 EDT
Created attachment 754357 [details]
## Logs rhevm
Comment 6 Yair Zaslavsky 2013-05-29 16:25:36 EDT
engine.log.2 shows -

nection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-05-28 16:47:55,056 ERROR [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: Error retreiving database metadata; nested exception is org.springframework.jdbc.support.MetaDataAccessException: Could not get Connection for extracting meta data; nested exception is org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-05-28 16:48:00,066 ERROR [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: Error retreiving database metadata; nested exception is org.springframework.jdbc.support.MetaDataAccessException: Could not get Connection for extracting meta data; nested exception is org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-05-28 16:48:05,154 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) Start time: 5/28/13 4:48 PM
2013-05-28 16:48:05,439 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (ajp-/127.0.0.1:8702-2) Failed to decrypt Data must start with zero
2013-05-28 16:48:05,440 ERROR [org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils] (ajp-/127.0.0.1:8702-2) Failed to decrypt value for property TruststorePass will be used encrypted value
2013-05-28 16:48:05,466 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) VDSBrokerFrontend: 5/28/13 4:48 PM
2013-05-28 16:48:05,469 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) CpuFlagsManager: 5/28/13 4:48 PM
2013-05-28 16:48:05,469 INFO  [org.ovirt.engine.core.bll.AuditLogCleanupManager] (ajp-/127.0.0.1:8702-2) Setting audit clean up manager to run at: 35 35 3 * * ?
2013-05-28 16:48:05,482 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) AuditLogCleanupManager: 5/28/13 4:48 PM
2013-05-28 16:48:05,485 INFO  [org.ovirt.engine.core.bll.TagsDirector] (ajp-/127.0.0.1:8702-2) TagsDirector initialization
2013-05-28 16:48:05,498 INFO  [org.ovirt.engine.core.bll.TagsDirector] (ajp-/127.0.0.1:8702-2) Tag root added to tree
2013-05-28 16:48:05,508 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) TagsDirector: 5/28/13 4:48 PM
2013-05-28 16:48:05,514 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) IsoDomainListSyncronizer: 5/28/13 4:48 PM
2013-05-28 16:48:05,533 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) InitHandlers: 5/28/13 4:48 PM
2013-05-28 16:48:05,543 WARN  [org.ovirt.engine.core.utils.ErrorTranslatorImpl] (ajp-/127.0.0.1:8702-2) Code MAC_ADDRESS_IS_IN_USE appears more than once in string table.
2013-05-28 16:48:05,543 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) ErrorTranslator: 5/28/13 4:48 PM
2013-05-28 16:48:05,544 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) VdsErrorTranslator: 5/28/13 4:48 PM
2013-05-28 16:48:05,544 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) Mark uncompleted jobs as UNKNOWN: 5/28/13 4:48 PM
2013-05-28 16:48:05,595 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) JobRepositoryCleanupManager: 5/28/13 4:48 PM
2013-05-28 16:48:05,597 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) AutoRecoveryManager: 5/28/13 4:48 P





1. There was DB issue - please elaborate on this.
2. Engine starting code ran again (you can see this here -

013-05-28 16:48:05,154 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) Start time: 5/28/13 4:48 PM )
3. InitBackendServicesOnStartupBean service which depends on backend bean did not start - (first appearance in log of this is on 2013-05-29 - on the next day ! 

013-05-29 08:38:15,585 INFO  [org.ovirt.engine.core.vdsbroker.ResourceManager] (ServerService Thread Pool -- 40) ResourceManager::ResourceManager::Entered

However, autorecovery code for example is started at backend bean, and as a result it did run, trying to get VdsManager from resource manager with no luck.

Is it possible to get the server.log/boot.log somehow?
Comment 7 vvyazmin@redhat.com 2013-05-30 03:57:35 EDT
Attached all relevant server.log
Comment 8 vvyazmin@redhat.com 2013-05-30 03:58:24 EDT
Created attachment 754703 [details]
## Logs rhevm server log
Comment 9 Yair Zaslavsky 2013-05-30 07:09:25 EDT
Hi,
In reply to comment #6 - Can you please explain what DB issues you had? How did you recover from?
Do you have a reproduce scenario here?
Comment 11 Juan Hernández 2013-06-03 05:35:46 EDT
What is really strange in this case is that the message that indicates that the backend has started comes from a thread from the pool that manages HTTP connections:

013-05-28 16:48:05,154 INFO  [org.ovirt.engine.core.bll.Backend] (ajp-/127.0.0.1:8702-2) Start time: 5/28/13 4:48 PM )

Note the name of the thread "ajp-/127.0.0.1:8702-2)". I would expect it to be invoked from one of the service threads of the application server, during startup, something like this:

2013-05-12 12:49:50,102 INFO  [org.ovirt.engine.core.bll.Backend] 
(ServerService Thread Pool -- 32) Start time: 5/12/13 12:49 PM

This is what happens in all the other logs attached to the bug.

Apparently the startup of the EJBs didn't work correctly. It may be a 
bug in EAP 6.1.
Comment 12 Barak 2013-06-06 08:11:43 EDT
Is this reproducible ?

Note You need to log in before you can comment on or make changes to this bug.