Bug 985876 - Failed power-on VM’s in amount power-on VM’s scenario.
Failed power-on VM’s in amount power-on VM’s scenario.
Status: CLOSED CURRENTRELEASE
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine (Show other bugs)
3.3.0
x86_64 Linux
unspecified Severity high
: ---
: 3.3.0
Assigned To: Arik
vvyazmin@redhat.com
virt
: Regression, Triaged
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-07-18 08:18 EDT by vvyazmin@redhat.com
Modified: 2015-09-22 09 EDT (History)
9 users (show)

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


Attachments (Terms of Use)
## Logs rhevm, vdsm, thread dump (1.97 MB, application/x-gzip)
2013-07-18 08:18 EDT, vvyazmin@redhat.com
no flags Details

  None (edit)
Description vvyazmin@redhat.com 2013-07-18 08:18:20 EDT
Created attachment 775296 [details]
## Logs rhevm, vdsm, thread dump

Description of problem: 
Failed power-on VM’s in amount power-on VM’s scenario. Command RunVmOnceCommand throw exception: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction


Version-Release number of selected component (if applicable):
RHEVM 3.3 - IS6 environment:

RHEVM: rhevm-3.3.0-0.9.master.el6ev.noarch
VDSM: vdsm-4.12.0-rc1.12.git8ee6885.el6.x86_64
LIBVIRT: libvirt-0.10.2-18.el6_4.9.x86_64
QEMU & KVM: qemu-kvm-rhev-0.12.1.2-2.355.el6_4.5.x86_64
SANLOCK: sanlock-2.6-2.el6.x86_64

How reproducible:
100%

Steps to Reproduce:
Power on 150 VM’s via PythonSDK. 
A script simulate 25 user connection, when each connection run Power-On vm.

Actual results:
Failed Power-On all VM’s

Expected results:
Succeed power on all VM’s

Impact on user:


Workaround:
Power on VM’s via UI.

Additional info:

/var/log/ovirt-engine/engine.log
2013-07-18 14:00:01,322 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (pool-5-thread-31) [478513f4] Running command: RunVmCommand internal: false. Entities affected :  ID: e40474f2-5943-4fec-b55d-b802373fb487 Type: VM
2013-07-18 14:02:18,672 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp-/127.0.0.1:8702-27) [789524e5] Failed to Acquire Lock to object EngineLock [exclusiveLocks= key: e40474f2-5943-4fec-b55d-b802373fb487 value: VM
, sharedLocks= ]
2013-07-18 14:02:18,678 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (ajp-/127.0.0.1:8702-27) [789524e5] CanDoAction of action RunVm failed. Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,ACTION_TYPE_FAILED_OBJECT_LOCKED
2013-07-18 14:03:23,751 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand] (Transaction Reaper Worker 0) Transaction rolled-back for command: org.ovirt.engine.core.bll.RunVmOnceCommand.
2013-07-18 14:03:23,779 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand] (Transaction Reaper Worker 0) Transaction rolled-back for command: org.ovirt.engine.core.bll.RunVmOnceCommand.
2013-07-18 14:03:23,826 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand] (Transaction Reaper Worker 0) Transaction rolled-back for command: org.ovirt.engine.core.bll.RunVmOnceCommand.
2013-07-18 14:03:24,031 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand] (Transaction Reaper Worker 0) Transaction rolled-back for command: org.ovirt.engine.core.bll.RunVmOnceCommand.
2013-07-18 14:03:24,041 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand] (ajp-/127.0.0.1:8702-13) Command org.ovirt.engine.core.bll.RunVmOnceCommand throw exception: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction
        at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:80) [spring-jdbc.jar:3.1.3.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:573) [spring-jdbc.jar:3.1.3.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637) [spring-jdbc.jar:3.1.3.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666) [spring-jdbc.jar:3.1.3.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:706) [spring-jdbc.jar:3.1.3.RELEASE]
        at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.executeCallInternal(PostgresDbEngineDialect.java:154) [dal.jar:]
        at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.doExecute(PostgresDbEngineDialect.java:120) [dal.jar:]
        at org.springframework.jdbc.core.simple.SimpleJdbcCall.execute(SimpleJdbcCall.java:181) [spring-jdbc.jar:3.1.3.RELEASE]
        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeImpl(SimpleJdbcCallsHandler.java:147) [dal.jar:]
        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeReadAndReturnMap(SimpleJdbcCallsHandler.java:112) [dal.jar:]
        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeReadList(SimpleJdbcCallsHandler.java:103) [dal.jar:]
        at org.ovirt.engine.core.dao.VdsDAODbFacadeImpl.getAllOfType(VdsDAODbFacadeImpl.java:88) [dal.jar:]
        at org.ovirt.engine.core.dao.VdsDAODbFacadeImpl.getAllOfTypes(VdsDAODbFacadeImpl.java:81) [dal.jar:]
        at org.ovirt.engine.core.bll.scheduling.SchedulingManager.schedule(SchedulingManager.java:150) [bll.jar:]
        at org.ovirt.engine.core.bll.RunVmCommand.getVdsToRunOn(RunVmCommand.java:643) [bll.jar:]
        at org.ovirt.engine.core.bll.RunVmCommand.runVm(RunVmCommand.java:230) [bll.jar:]
        at org.ovirt.engine.core.bll.RunVmCommand.executeVmCommand(RunVmCommand.java:306) [bll.jar:]
        at org.ovirt.engine.core.bll.VmCommand.executeCommand(VmCommand.java:85) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1127) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1212) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1853) [bll.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:210) [utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:149) [utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:118) [utils.jar:]
        at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1230) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:365) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:404) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:387) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.RunAction(Backend.java:345) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor193.invoke(Unknown Source) [:1.7.0_25]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_25]
        at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_25]
        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.bll.interceptors.ThreadLocalSessionCleanerInterceptor.injectWebContextToThreadLocal(ThreadLocalSessionCleanerInterceptor.java:13) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source) [:1.7.0_25]



/var/log/vdsm/vdsm.log
Comment 3 Arik 2013-08-13 04:40:01 EDT
It should be solved now by the fix for bz 989916.
Can you please check if it is still reproducible with the latest version?

I also believe that it is not a regression, do we know of any version in which it worked?
Comment 4 vvyazmin@redhat.com 2013-08-15 08:13:14 EDT
Tested on RHEVM 3.3 - IS10 environment:

RHEVM:  rhevm-3.3.0-0.15.master.el6ev.noarch
PythonSDK:  rhevm-sdk-python-3.3.0.10-1.el6ev.noarch
VDSM:  vdsm-4.12.0-61.git8178ec2.el6ev.x86_64
LIBVIRT:  libvirt-0.10.2-18.el6_4.9.x86_64
QEMU & KVM:  qemu-kvm-rhev-0.12.1.2-2.355.el6_4.5.x86_64
SANLOCK:  sanlock-2.8-1.el6.x86_64

And it works OK.

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