This service will be undergoing maintenance at 00:00 UTC, 2017-10-23 It is expected to last about 30 minutes
Bug 1269531 - Psql exceptions while performing multiple operations with Cinder provider cause engine timeouts
Psql exceptions while performing multiple operations with Cinder provider cau...
Status: CLOSED CURRENTRELEASE
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine (Show other bugs)
3.6.0
Unspecified Unspecified
unspecified Severity high
: ovirt-3.6.1
: 3.6.0
Assigned To: Daniel Erez
Ori Gofen
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-10-07 09:56 EDT by Ori Gofen
Modified: 2016-03-10 06:59 EST (History)
10 users (show)

See Also:
Fixed In Version: 3.6.0-16
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Storage
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


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


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

  None (edit)
Description Ori Gofen 2015-10-07 09:56:05 EDT
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 03:58:11 EDT
Looks like the usual race condition in the search mechanism.

Daniel, please take a look?
Comment 2 Eyal Edri 2015-10-14 11:39:36 EDT
fixed version & build id
Comment 3 Ori Gofen 2015-10-19 08:22:12 EDT
rhevm-3.6.0.1-0.1.el6.noarch
Comment 4 Allon Mureinik 2016-03-10 05:35:37 EST
RHEV 3.6.0 has been released, setting status to CLOSED CURRENTRELEASE
Comment 5 Allon Mureinik 2016-03-10 05:37:18 EST
RHEV 3.6.0 has been released, setting status to CLOSED CURRENTRELEASE
Comment 6 Allon Mureinik 2016-03-10 05:42:57 EST
RHEV 3.6.0 has been released, setting status to CLOSED CURRENTRELEASE
Comment 7 Allon Mureinik 2016-03-10 06:59:47 EST
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.