Bug 880169

Summary: ovrit-engine-backend:.rollbackQuota ignores disabled quota
Product: Red Hat Enterprise Virtualization Manager Reporter: Omri Hochman <ohochman>
Component: ovirt-engineAssignee: Doron Fediuck <dfediuck>
Status: CLOSED CURRENTRELEASE QA Contact: yeylon <yeylon>
Severity: medium Docs Contact:
Priority: medium    
Version: 3.1.0CC: acathrow, cpelland, dfediuck, iheim, jkt, lpeer, oramraz, Rhev-m-bugs, srevivo, yeylon
Target Milestone: ---Keywords: ZStream
Target Release: 3.2.0   
Hardware: x86_64   
OS: Linux   
Whiteboard: sla
Fixed In Version: SF1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 881783 (view as bug list) Environment:
Last Closed: 2014-03-26 21:06:05 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: SLA RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 881783    
Attachments:
Description Flags
console.log
none
engine.log none

Description Omri Hochman 2012-11-26 12:28:27 UTC
ovrit-engine-backend[scalability]:.rollbackQuota query twice DiskDaoDbFacadeImpl.getAllForVm for vmAction when quota is disabled.

Scenario:
*********
1) Disable DC quota (default quota value is disabled).
2) Create VM (Make sure It's Nota stateless VM).
3) Attempt to runVM  .
4) Attempt to StopVM.
5) Check the thread dump :  
   - > /var/log/ovirt-engine/console.log
   -   kill -3 `pgrep java' 
   -   less /var/log/ovirt-engine/console.log
   -   search for '.rollbackQuota'

Results:
*******
A) .rollbackQuota is querying twice ".DiskDaoDbFacadeImpl.getAllForVm" for each vmAction.  
B) .rollbackQuota should call those queries only when:
    - Quota is enabled on DC. 
    - The VMs are stateless. 

console.log :
************
"pool-4-thread-5" prio=10 tid=0x00007f2a14009800 nid=0x4003 runnable [0x00007f29fbbb9000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:150)
        at java.net.SocketInputStream.read(SocketInputStream.java:121)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:135)
        at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:104)
        at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
        at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:259)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1620)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)
        - locked <0x00000000c3ef8660> (a org.postgresql.core.v3.QueryExecutorImpl)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:479)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:367)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:271)
        at org.jboss.jca.adapters.jdbc.CachedPreparedStatement.executeQuery(CachedPreparedStatement.java:107)
        at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:462)
        at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:644)
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:587)
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637)
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666)
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:706)
        at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.executeCallInternal(PostgresDbEngineDialect.java:155)
        at org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall.doExecute(PostgresDbEngineDialect.java:121)
        at org.springframework.jdbc.core.simple.SimpleJdbcCall.execute(SimpleJdbcCall.java:181)
        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeImpl(SimpleJdbcCallsHandler.java:124)
at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeReadAndReturnMap(SimpleJdbcCallsHandler.java:75)
        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeReadList(SimpleJdbcCallsHandler.java:66)
        at org.ovirt.engine.core.dao.DiskDaoDbFacadeImpl.getAllForVm(DiskDaoDbFacadeImpl.java:31)
        at org.ovirt.engine.core.dao.DiskDaoDbFacadeImpl.getAllForVm(DiskDaoDbFacadeImpl.java:24)
        at org.ovirt.engine.core.bll.VmHandler.updateDisksFromDb(VmHandler.java:253)
        at org.ovirt.engine.core.bll.StopVmCommandBase.rollbackQuota(StopVmCommandBase.java:251)
        at org.ovirt.engine.core.bll.StopVmCommandBase.setSucceeded(StopVmCommandBase.java:276)
        at org.ovirt.engine.core.bll.ShutdownVmCommand.Perform(ShutdownVmCommand.java:89)
        at org.ovirt.engine.core.bll.VmOperationCommandBase.ExecuteVmCommand(VmOperationCommandBase.java:34)
        at org.ovirt.engine.core.bll.StopVmCommandBase.ExecuteVmCommand(StopVmCommandBase.java:95)
        at org.ovirt.engine.core.bll.VmCommand.executeCommand(VmCommand.java:78)
        at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:876)
        at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:973)
        at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1372)
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:168)
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:107)
        at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:991)
        at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:291)
        at org.ovirt.engine.core.bll.MultipleActionsRunner.executeValidatedCommands(MultipleActionsRunner.java:182)
        at org.ovirt.engine.core.bll.MultipleActionsRunner.RunCommands(MultipleActionsRunner.java:162)
        at org.ovirt.engine.core.bll.MultipleActionsRunner$1.run(MultipleActionsRunner.java:84)
        at org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:64)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)

Comment 1 Omri Hochman 2012-11-26 12:28:56 UTC
Created attachment 651934 [details]
console.log

Comment 2 Doron Fediuck 2012-11-26 12:43:49 UTC
(In reply to comment #0)

(snip)

> 
> Results:
> *******
> A) .rollbackQuota is querying twice ".DiskDaoDbFacadeImpl.getAllForVm" for
> each vmAction.  

Need verification on this item.

> B) .rollbackQuota should call those queries only when:
>     - Quota is enabled on DC. 

Agreed.

>     - The VMs are stateless. 
> 

Not exactly. The storage part should be handled only for stateless. Otherwise
each stopped VM needs to release the run-time quota, so roll-back is needed.

Comment 3 Doron Fediuck 2012-11-26 16:29:36 UTC
(In reply to comment #2)
> (In reply to comment #0)
 
(snip)
 
> > 
> > Results:
> > *******
> > A) .rollbackQuota is querying twice ".DiskDaoDbFacadeImpl.getAllForVm" for
> > each vmAction.  
> 
> Need verification on this item.
> 

After checking it, this is a misunderstanding, since we have function overloading. No need for a fix here.

> > B) .rollbackQuota should call those queries only when:
> >     - Quota is enabled on DC. 
> 
> Agreed.
> 

The only fix needed here is check for quota state (ie0 not disabled), and improve by handling storage just for stateless VMs.

Comment 4 Doron Fediuck 2012-11-26 16:34:46 UTC
Removed the 3.2 flag, as this issue is relevant for 3.1.z only.
In 3.2 we have quota improvements which removed these code parts.

Comment 5 Simon Grinberg 2012-11-27 14:14:43 UTC
(In reply to comment #4)
> Removed the 3.2 flag, as this issue is relevant for 3.1.z only.
> In 3.2 we have quota improvements which removed these code parts.

Still has to have the flag for QE to verify there is no regression.

Comment 12 Omri Hochman 2012-11-29 20:45:43 UTC
Created attachment 654550 [details]
engine.log

Comment 13 ofri 2012-12-03 06:50:40 UTC
Posted to downstream: https://gerrit.eng.lab.tlv.redhat.com/#/c/3500/

Omri, Please rerun the test to verify the fix.

Comment 14 Omri Hochman 2012-12-06 09:51:40 UTC
Fix looks OK with the provided .jar - there were no calls for '.rollbackQuota':
*******************************************************************************
"pool-3-thread-50" prio=10 tid=0x00007f8d8c195000 nid=0x503b waiting on condition [0x00007f8d4dd5b000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000ef081f08> (a java.util.concurrent.FutureTask$Sync)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1033)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1326)
        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:257)
        at java.util.concurrent.FutureTask.get(FutureTask.java:119)
        at org.ovirt.engine.core.vdsbroker.xmlrpc.XmlRpcUtils$AsyncProxy.invoke(XmlRpcUtils.java:160)
        at $Proxy29.destroy(Unknown Source)
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsServerWrapper.destroy(VdsServerWrapper.java:45)
        at org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand.ExecuteVdsBrokerCommand(DestroyVDSCommand.java:19)
        at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.ExecuteVDSCommand(VdsBrokerCommand.java:91)
        at org.ovirt.engine.core.vdsbroker.VDSCommandBase.ExecuteCommand(VDSCommandBase.java:63)
        at org.ovirt.engine.core.dal.VdcCommandBase.Execute(VdcCommandBase.java:41)
        at org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand.ExecuteVdsIdCommand(DestroyVmVDSCommand.java:36)
        at org.ovirt.engine.core.vdsbroker.VdsIdVDSCommandBase.ExecuteVDSCommand(VdsIdVDSCommandBase.java:49)
        - locked <0x00000000c3512038> (a java.lang.Object)
        at org.ovirt.engine.core.vdsbroker.VDSCommandBase.ExecuteCommand(VDSCommandBase.java:63)
        at org.ovirt.engine.core.dal.VdcCommandBase.Execute(VdcCommandBase.java:41)
        at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:388)
        at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.RunVdsCommand(VDSBrokerFrontendImpl.java:33)
        at org.ovirt.engine.core.bll.StopVmCommandBase.Destroy(StopVmCommandBase.java:80)
        at org.ovirt.engine.core.bll.StopVmCommand.Perform(StopVmCommand.java:15)
        at org.ovirt.engine.core.bll.VmOperationCommandBase.ExecuteVmCommand(VmOperationCommandBase.java:34)
     at org.ovirt.engine.core.bll.StopVmCommandBase.ExecuteVmCommand(StopVmCommandBase.java:95)
        at org.ovirt.engine.core.bll.VmCommand.executeCommand(VmCommand.java:78)
        at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:876)
        at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:973)
        at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1372)
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:168)
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:107)
        at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:991)
        at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:291)
        at org.ovirt.engine.core.bll.MultipleActionsRunner.executeValidatedCommands(MultipleActionsRunner.java:182)
        at org.ovirt.engine.core.bll.MultipleActionsRunner.RunCommands(MultipleActionsRunner.java:162)
        at org.ovirt.engine.core.bll.MultipleActionsRunner$1.run(MultipleActionsRunner.java:84)
        at org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:64)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)

Comment 15 ofri 2012-12-11 08:17:16 UTC
Fix verified by Omri Hochman

Comment 17 Omri Hochman 2012-12-11 13:27:11 UTC
No regression found after implementing the fix on my environment. there were no calls by '.rollbackQuota' when quota is disabled.

Comment 18 vvyazmin@redhat.com 2013-07-21 15:42:20 UTC
No issues are found

Verified, tested on 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