On Thu, Oct 22, 2015 at 11:50 AM, Gianluca Cecchi <gianluca.cecchi@gmail.com> wrote:

On Wed, Oct 21, 2015 at 6:15 PM, Simone Tiraboschi <stirabos@redhat.com> wrote:

It pools engine REST API checking the host status for 10 minutes till it become 'up' or 'non_operational'. In your case it reached the 10 minutes timeout.

Please check engine and host-deploy logs on the engine VM.

Ok. 

What I see inside ovirt-host-deploy log file 

 2015-10-21 17:20:26 DEBUG otopi.plugins.otopi.packagers.dnfpackager dnfpackager._boot:178 Cannot initialize minidnf

Traceback (most recent call last):

  File "/tmp/ovirt-xP0lq4KMou/otopi-plugins/otopi/packagers/dnfpackager.py", line 165, in _boot

    constants.PackEnv.DNF_DISABLED_PLUGINS

  File "/tmp/ovirt-xP0lq4KMou/otopi-plugins/otopi/packagers/dnfpackager.py", line 75, in _getMiniDNF

    from otopi import minidnf

  File "/tmp/ovirt-xP0lq4KMou/pythonlib/otopi/minidnf.py", line 9, in <module>

    import dnf

ImportError: No module named dnf

...

2015-10-21 17:36:33 DEBUG otopi.plugins.otopi.dialog.machine dialog.__logString:219 DIALOG:SEND       ### Please input VDSM certificate chain that matches certificate request, top is issuer

2015-10-21 17:36:33 DEBUG otopi.plugins.otopi.dialog.machine dialog.__logString:219 DIALOG:SEND       ###

2015-10-21 17:36:33 DEBUG otopi.plugins.otopi.dialog.machine dialog.__logString:219 DIALOG:SEND       ### type '--=451b80dc-996f-432e-9e4f-2b29ef6d1141=--' in own line to mark end, '--=451b80dc-996f-ABORT-9e4f-2b29ef6d1141=--' aborts

2015-10-21 17:36:33 DEBUG otopi.context context._executeMethod:156 method exception

Traceback (most recent call last):

  File "/tmp/ovirt-xP0lq4KMou/pythonlib/otopi/context.py", line 146, in _executeMethod

    method['method']()

  File "/tmp/ovirt-xP0lq4KMou/otopi-plugins/ovirt-host-common/vdsm/pki.py", line 319, in _misc

    '\n\nPlease input VDSM certificate chain that '

  File "/tmp/ovirt-xP0lq4KMou/otopi-plugins/otopi/dialog/machine.py", line 207, in queryMultiString

    v = self._readline()

  File "/tmp/ovirt-xP0lq4KMou/pythonlib/otopi/dialog.py", line 263, in _readline

    raise IOError(_('End of file'))

IOError: End of file

2015-10-21 17:36:33 ERROR otopi.context context._executeMethod:165 Failed to execute stage 'Misc configuration': End of file

2015-10-21 17:36:33 DEBUG otopi.transaction transaction.abort:134 aborting 'Yum Transaction'

2015-10-21 17:36:33 INFO otopi.plugins.otopi.packagers.yumpackager yumpackager.info:95 Yum Performing yum transaction rollback

Loaded plugins: fastestmirror, langpacks

And in engine.log

2015-10-21 15:19:11,061 INFO  [org.ovirt.engine.core.bll.Backend] (ServerService Thread Pool -- 43) [] 

Started task scheduler org.ovirt.engine.core.utils.timer.SchedulerUtilQuartzImpl@7160a32a

2015-10-21 15:19:11,321 INFO  [org.ovirt.engine.core.bll.Backend] (ServerService Thread Pool -- 43) [] 

Started task scheduler org.ovirt.engine.core.utils.timer.DBSchedulerUtilQuartzImpl@55760e6a

2015-10-21 15:19:11,746 INFO  [org.ovirt.engine.core.bll.Backend] (ServerService Thread Pool -- 43) [] 

Start org.ovirt.engine.core.dal.utils.CacheManager@2a4c024b 

2015-10-21 15:19:11,957 WARN  [org.ovirt.engine.core.utils.ConfigUtilsBase] (ServerService Thread Pool 

-- 43) [] Could not find enum value for option: 'MigrateDowntime'

2015-10-21 15:19:11,957 WARN  [org.ovirt.engine.core.utils.ConfigUtilsBase] (ServerService Thread Pool 

-- 43) [] Could not find enum value for option: 'MigrateDowntime'

2015-10-21 15:19:11,957 WARN  [org.ovirt.engine.core.utils.ConfigUtilsBase] (ServerService Thread Pool 

-- 43) [] Could not find enum value for option: 'MigrateDowntime'

2015-10-21 15:19:11,958 WARN  [org.ovirt.engine.core.utils.ConfigUtilsBase] (ServerService Thread Pool 

-- 43) [] Could not find enum value for option: 'MigrateDowntime'

2015-10-21 15:19:11,958 WARN  [org.ovirt.engine.core.utils.ConfigUtilsBase] (ServerService Thread Pool 

-- 43) [] Could not find enum value for option: 'MigrateDowntime'

2015-10-21 15:19:11,958 WARN  [org.ovirt.engine.core.utils.ConfigUtilsBase] (ServerService Thread Pool 

-- 43) [] Could not find enum value for option: 'MigrateDowntime'

2015-10-21 15:19:11,964 ERROR [org.ovirt.engine.core.dal.dbbroker.generic.DBConfigUtils] (ServerService Thread Pool -- 43) [] Error parsing option 'AutoRecoveryAllowedTypes' value: org.codehaus.jackson.JsonParseException: Unexpected character ('\' (code 92)): was expecting double-quote to start field name

 at [Source: java.io.StringReader@21b12337; line: 1, column: 3]

2015-10-21 15:19:11,969 INFO  [org.ovirt.engine.core.utils.osinfo.OsInfoPreferencesLoader] (ServerService Thread Pool -- 43) [] Loading file '/etc/ovirt-engine/osinfo.conf.d/00-defaults.properties'

2015-10-21 15:19:12,322 INFO  [org.ovirt.engine.core.bll.Backend] (ServerService Thread Pool -- 43) [] Running ovirt-engine 3.6.0.1-1.el7.centos

2015-10-21 15:19:12,322 INFO  [org.ovirt.engine.core.bll.CpuFlagsManagerHandler] (ServerService Thread Pool -- 43) [] Start initializing dictionaries

2015-10-21 15:19:12,328 INFO  [org.ovirt.engine.core.bll.CpuFlagsManagerHandler] (ServerService Thread Pool -- 43) [] Finished initializing dictionaries

...

2015-10-21 15:35:08,852 ERROR [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-61) [] Timer update runtime info failed. Exception:: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000451: The connection manager is shutdown: java:/ENGINEDataSource

        at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:80) [spring-jdbc.jar:3.1.1.RELEASE]

        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:573) [spring-jdbc.jar:3.1.1.RELEASE]

        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637) [spring-jdbc.jar:3.1.1.RELEASE]

        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666) [spring-jdbc.jar:3.1.1.RELEASE]

        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:706) [spring-jdbc.jar:3.1.1.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.1.RELEASE]

        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeImpl(SimpleJdbcCallsHandler.java:147) [dal.jar:]

        at org.ovirt.engine.core.dal.dbbroker.SimpleJdbcCallsHandler.executeReadList(SimpleJdbcCallsHandler.java:109) [dal.jar:]

        at org.ovirt.engine.core.dao.VdsDaoImpl.get(VdsDaoImpl.java:53) [dal.jar:]

        at org.ovirt.engine.core.dao.VdsDaoImpl.get(VdsDaoImpl.java:47) [dal.jar:]

        at org.ovirt.engine.core.vdsbroker.VdsManager.refreshCachedVds(VdsManager.java:278) [vdsbroker.

 jar:]

        at org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:208) [vdsbroker.jar:]

        at sun.reflect.GeneratedMethodAccessor133.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.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81) [scheduler.jar:]

        at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52) [scheduler.jar:]

        at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:]

        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:]

Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000451: The connection manager is shutdown: java:/ENGINEDataSource

        at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:154)

        at sun.reflect.GeneratedMethodAccessor59.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.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:414) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]

        at org.jboss.weld.bean.builtin.CallableMethodHandler.invoke(CallableMethodHandler.java:42) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]

        at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]

        at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:100) [weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]

        at org.jboss.weldx.sql.CommonDataSource$DataSource$Wrapper$1587847696$Proxy$_$$_Weld$Proxy$.getConnection(Unknown Source)

        at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111) [spring-jdbc.jar:3.1.1.RELEASE]

        at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77) [spring-jdbc.jar:3.1.1.RELEASE]

        ... 20 more

Caused by: javax.resource.ResourceException: IJ000451: The connection manager is shutdown: java:/ENGINEDataSource

        at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:371)

        at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:421)

        at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:515)

        at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:146)

        ... 30 more

2015-10-21 15:35:11,887 ERROR [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-65) [] Timer update runtime info failed. Exception:: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is java.sql.SQLException: javax.resource.ResourceException: IJ000451: The connection manager is shutdown: java:/ENGINEDataSource