Bug 1269531 - Psql exceptions while performing multiple operations with Cinder provider cause engine timeouts
Summary: Psql exceptions while performing multiple operations with Cinder provider cau...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 3.6.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ovirt-3.6.1
: 3.6.0
Assignee: Daniel Erez
QA Contact: Ori Gofen
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-10-07 13:56 UTC by Ori Gofen
Modified: 2016-03-10 11:59 UTC (History)
10 users (show)

Fixed In Version: 3.6.0-16
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:
oVirt Team: Storage
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
log (12.43 MB, text/plain)
2015-10-07 13:56 UTC, Ori Gofen
no flags Details


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 47229 0 master MERGED webadmin: disks tab - fix quota visibility event handler Never
oVirt gerrit 47253 0 ovirt-engine-3.6 MERGED webadmin: disks tab - fix quota visibility event handler Never
oVirt gerrit 47259 0 ovirt-engine-3.6.0 MERGED webadmin: disks tab - fix quota visibility event handler Never

Description Ori Gofen 2015-10-07 13:56:05 UTC
Created attachment 1080690 [details]
log

Description of problem:
While performing multi-threaded operations of add vm+cinder disk and removing it, have noticed the engine reports very slowly, the engine log was flooded with postgresql ERROR messages such as:

2015-10-07 14:14:34,404 ERROR [org.ovirt.engine.core.bll.SearchQuery] (ajp-/127.0.0.1:8702-24) [] Query 'SearchQuery' failed: StatementCallback; bad SQL grammar [SELECT * FRO
M ((SELECT distinct providers.* FROM  providers  )  ORDER BY name ASC) as T1 OFFSET (1 -1) LIMIT 100]; nested exception is org.postgresql.util.PSQLException: The column name
disk_storage_type was not found in this ResultSet.
2015-10-07 14:14:34,404 ERROR [org.ovirt.engine.core.bll.SearchQuery] (ajp-/127.0.0.1:8702-24) [] Exception: org.springframework.jdbc.BadSqlGrammarException: StatementCallbac
k; bad SQL grammar [SELECT * FROM ((SELECT distinct providers.* FROM  providers  )  ORDER BY name ASC) as T1 OFFSET (1 -1) LIMIT 100]; nested exception is org.postgresql.util
.PSQLException: The column name disk_storage_type was not found in this ResultSet.
        at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:98) [spring-jdbc.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) [spring-jdbc.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80) [spring-jdbc.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80) [spring-jdbc.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:407) [spring-jdbc.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:456) [spring-jdbc.jar:3.1.1.RELEASE]
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:464) [spring-jdbc.jar:3.1.1.RELEASE]
        at org.ovirt.engine.core.dao.DiskDaoImpl.getAllWithQuery(DiskDaoImpl.java:121) [dal.jar:]
        at org.ovirt.engine.core.bll.SearchQuery.genericSearch(SearchQuery.java:281) [bll.jar:]
        at org.ovirt.engine.core.bll.SearchQuery.genericSearch(SearchQuery.java:269) [bll.jar:]
        at org.ovirt.engine.core.bll.SearchQuery.searchDisk(SearchQuery.java:315) [bll.jar:]
        at org.ovirt.engine.core.bll.SearchQuery.executeQueryCommand(SearchQuery.java:127) [bll.jar:]
        at org.ovirt.engine.core.bll.QueriesCommandBase.executeCommand(QueriesCommandBase.java:82) [bll.jar:]
        at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) [dal.jar:]
        at org.ovirt.engine.core.bll.Backend.runQueryImpl(Backend.java:537) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runQuery(Backend.java:511) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor71.invoke(Unknown Source) [:1.7.0_85]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_85]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52) [jboss-as-ee.jar:7.5.3.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63) [jboss-as-ee.jar:7.5.3.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:74) [jboss-as-weld.jar:7.5.3.Final-redhat-2]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:84) [jboss-as-weld.jar:7.5.3.Final-redhat-2]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:97) [jboss-as-weld.jar:7.5.3.Final-redhat-2]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63) [jboss-as-ee.jar:7.5.3.Final-redhat-2]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation.jar:1.1.2.Final-redhat-1]
        at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source) [:1.7.0_85]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_85]
        at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89) [jboss-as-ee.jar:7.5.3

the ui seem to drift as if it's calculating something big, it seems similar to the Future.get java interface bug, because of those time outs and because of the fact that I have run the same tests a while ago on the pre-integration environment without noticing anything like it.
 

Version-Release number of selected component (if applicable):
rhevm-3.6-14

How reproducible:
?

Steps to Reproduce:
will go over my tests and provide a detailed reproducer, as I mentioned, have encountered this behaviour while creating and removing vms with cinder disk (different vms, same time)

Actual results:
engine becomes very slow, time outs, log is flooded with postgresql exceptions

Expected results:
like on Fedora!

Additional info:

Comment 1 Allon Mureinik 2015-10-08 07:58:11 UTC
Looks like the usual race condition in the search mechanism.

Daniel, please take a look?

Comment 2 Eyal Edri 2015-10-14 15:39:36 UTC
fixed version & build id

Comment 3 Ori Gofen 2015-10-19 12:22:12 UTC
rhevm-3.6.0.1-0.1.el6.noarch

Comment 4 Allon Mureinik 2016-03-10 10:35:37 UTC
RHEV 3.6.0 has been released, setting status to CLOSED CURRENTRELEASE

Comment 5 Allon Mureinik 2016-03-10 10:37:18 UTC
RHEV 3.6.0 has been released, setting status to CLOSED CURRENTRELEASE

Comment 6 Allon Mureinik 2016-03-10 10:42:57 UTC
RHEV 3.6.0 has been released, setting status to CLOSED CURRENTRELEASE

Comment 7 Allon Mureinik 2016-03-10 11:59:47 UTC
RHEV 3.6.0 has been released, setting status to CLOSED CURRENTRELEASE


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