Bug 976450

Summary:	[engine-backend] engine is configured to check it's connection to postgresql every 0.05 seconds instead of every 2 seconds
Product:	[Retired] oVirt	Reporter:	Elad <ebenahar>
Component:	ovirt-engine-core	Assignee:	Nobody's working on this, feel free to take it <nobody>
Status:	CLOSED WORKSFORME	QA Contact:
Severity:	medium	Docs Contact:
Priority:	unspecified
Version:	unspecified	CC:	acathrow, ebenahar, iheim, jkt, juan.hernandez
Target Milestone:	---
Target Release:	---
Hardware:	x86_64
OS:	Unspecified
Whiteboard:	infra
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2013-07-14 06:29:51 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Elad 2013-06-20 15:18:49 UTC

Description of problem:
engine is configured to check it's connection to postgresql every 0.05 seconds instead every 2 seconds

Version-Release number of selected component (if applicable):
commit 807647a6506f107c5927596e9488feb7b4df21ab

How reproducible:
100%

Steps to Reproduce:
1. shutdown engine (power off to the machine)
.

Actual results:
after cold reboot to the machine, postgresql is not coming up and as a result, ovirt-engine process is unable to start.
engine is checking it's connection to postgresql every 0.05 seconds and report about it in engine.log,  which causing to a log flood.

2013-06-19 13:15:49,927 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,001 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,055 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,106 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,168 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,231 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,275 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,318 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-2) Error in getting DB connection. The database is inaccessible. Original exception is: DataAccessResourceFailureException: E
rror 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.Cann
otGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/ENGINEDataSource
2013-06-19 13:15:50,360 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-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-06-19 13:15:50,403 ERROR [org.ovirt.engine.core.bll.Backend] (MSC service thread 1-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


Expected results:
engine should check the connection every 2 seconds

Additional info:

engine.conf:
ENGINE_DB_CHECK_INTERVAL=2

Comment 1 Itamar Heim 2013-06-21 06:11:31 UTC

I'm not sure this is a bug - the check happens on each db access attempt, which with multiple threads could happen at this frequency.
so i'm leaning to 'notabug'
juan - thoughts?

Comment 2 Juan Hernández 2013-06-24 09:16:48 UTC

The ENGINE_DB_CHECK_INTERVAL parameter is measured in milliseconds, so 2 actually means 0.002 seconds. The default value for this parameter is 1000ms, check the /usr/share/ovirt-engine/conf/engine.conf.defaults file. If you want to check the database every 2 seconds then you need to change it to 2000 (in /etc/ovirt-engine/engine.conf, not in /usr/share/ovirt-engine/conf/engine.conf.defaults).

Has the value in engine.conf been changed manually?

Comment 3 Elad 2013-06-24 10:42:44 UTC

It wasn't configured manually  on engine.conf

Comment 4 Juan Hernández 2013-06-24 11:33:58 UTC

The only way this parameter can be automatically added is during and upgrade, and in that case the value is taken from the value of the former ConnectionCheckInterval parameter in the same /etc/ovirt-engine/engine.conf file. So if this installation was upgraded then the value was 2 before the upgrade as well, and 2 wasn't the default either, so it must have been modified manually.

Comment 5 Itamar Heim 2013-07-11 17:53:26 UTC

Elad - can you reproduce on any other environment?

Comment 6 Elad 2013-07-13 14:44:47 UTC

I've encountered this after a power shortage, with an upstream setup. On downstream it is configured to check DB connection every 1000 milliseconds, as Juan claimed. However, this value was never changed on the original upstream engine. 
I tried to reproduce this on downstream when postgresql service was configured to not start with server startup, and after engine had active connections to it's DB (I cold restarted the server while some LSM tasks ran). When server came up, the engine checked it's connection to DB every 5 seconds:

2013-07-13 17:42:31,526 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-07-13 17:42:36,535 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


Should we close this bug?

Comment 7 Itamar Heim 2013-07-14 06:29:51 UTC

closing - lets evaluate if reproduces some more.