4:40 a.m.
This is a multi-part message in MIME format.
--------------D85A420919595D580C076AD7
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit
Hi,
we have a CQ failure in add_dc test. I can see at engine long that we
have an issue with 'extension.aaa.jdbc.binding.api.AuthnExtension'
I don't think that the patch reported was the actual cause of the
failure. Yesterday we were failing on missing package ovirt-cockpit-sso
which we added to our repos. and I think perhaps we now exposed an issue
with sso support which was undiscovered before.
**
*Link to suspected patches: *
**
These are the reported patches:
https://gerrit.ovirt.org/#/c/83790/
https://gerrit.ovirt.org/#/c/83779/
*
**
Here is the original patch for the sso support:
https://gerrit.ovirt.org/#/c/82997/
Link to Job:
*http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/
**
*Link to all logs:*
***
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifact/
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifact/
(Relevant) error snippet from the log:
<error>
*
2017-11-15 16:50:07,115-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Loading extension 'internal-authn'
2017-11-15 16:50:07,118-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Extension 'internal-authn' loaded
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config BEGIN
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.profile.name: internal
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authn
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.authz.plugin: internal-authz
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authn
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config END
2017-11-15 16:50:07,119-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Loading extension 'internal-authz'
2017-11-15 16:50:07,120-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Extension 'internal-authz' loaded
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config BEGIN
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authz
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthzExtension
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authz
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config END
2017-11-15 16:50:07,121-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Initializing extension 'internal-authn'
2017-11-15 16:50:07,182-05 ERROR
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Unexpected Exception invoking:
EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2]
2017-11-15 16:50:07,182-05 DEBUG
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Exception:: org.postgresql.util.PSQLException: FATAL: the database system
is shutting down
at
org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:398)
[postgresql.jar:]
at
org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:173)
[postgresql.jar:]
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:64)
[postgresql.jar:]
at
org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:136)
[postgresql.jar:]
at
org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:29)
[postgresql.jar:]
at
org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:21)
[postgresql.jar:]
at
org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:31)
[postgresql.jar:]
at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
[postgresql.jar:]
at org.postgresql.Driver.makeConnection(Driver.java:393) [postgresql.jar:]
at org.postgresql.Driver.connect(Driver.java:267) [postgresql.jar:]
at java.sql.DriverManager.getConnection(DriverManager.java:664) [rt.jar:1.8.0_151]
at java.sql.DriverManager.getConnection(DriverManager.java:247) [rt.jar:1.8.0_151]
at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.DataSourceProvider$1.invoke(DataSourceProvider.java:86)
[ovirt-engine-extension-aaa-jdbc.jar:]
at com.sun.proxy.$Proxy177.getConnection(Unknown Source)
at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.SchemaAwareDataSource.getConnection(SchemaAwareDataSource.java:41)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.ExtensionUtils.checkDbVersion(ExtensionUtils.java:146)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.doInit(AuthnExtension.java:114)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.invoke(AuthnExtension.java:56)
[ovirt-engine-extension-aaa-jdbc.jar:]
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:49)
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:73)
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:109)
at
org.ovirt.engine.core.extensions.mgr.ExtensionsManager.initialize(ExtensionsManager.java:315)
at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.initialize(SsoExtensionsManager.java:91)
at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.<init>(SsoExtensionsManager.java:28)
at
org.ovirt.engine.core.sso.context.SsoContextListener.contextInitialized(SsoContextListener.java:28)
at
io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:205)
at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:174)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:239)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:99)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[rt.jar:1.8.0_151]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[rt.jar:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[rt.jar:1.8.0_151]
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
2017-11-15 16:50:07,185-05 ERROR [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Error in activating extension
'internal-authn': FATAL: the database system is shutting down
2017-11-15 16:50:07,185-05 DEBUG [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Class: class
org.ovirt.engine.core.extensions.mgr.ExtensionInvokeCommandFailedException
**
*</error>*
**
--------------D85A420919595D580C076AD7
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: 7bit
<html>
<head>
<meta http-equiv="content-type" content="text/html;
charset=utf-8">
</head>
<body text="#000000" bgcolor="#FFFFFF">
<p>Hi, <br>
</p>
<p>we have a CQ failure in add_dc test. I can see at engine long
that we have an issue with
'extension.aaa.jdbc.binding.api.AuthnExtension'</p>
<p>I don't think that the patch reported was the actual cause of the
failure. Yesterday we were failing on missing package
ovirt-cockpit-sso which we added to our repos. and I think perhaps
we now exposed an issue with sso support which was undiscovered
before. <br>
</p>
<p><br>
</p>
<p><b style="font-weight:normal;"
id="docs-internal-guid-5859b7a1-c45f-74ff-f3ff-ccb59b69f04d">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;">Link
to suspected patches:
</span></p>
</b><span style="font-weight:normal;">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;">These
are the reported patches:
</span></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;"><a
class="moz-txt-link-freetext"
href="https://gerrit.ovirt.org/#/c/83790/">https://gerrit.ov...
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;"><a
class="moz-txt-link-freetext"
href="https://gerrit.ovirt.org/#/c/83779/">https://gerrit.ov...
</span><b style="font-weight:normal;"
id="docs-internal-guid-5859b7a1-c45f-74ff-f3ff-ccb59b69f04d">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;"><b>
</b></span></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><font
face="Arial">Here is the original patch for the sso support:
<br>
</font></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><font
face="Arial"><a class="moz-txt-link-freetext"
href="https://gerrit.ovirt.org/#/c/82997/">https://gerrit.ov...
<br>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;">Link
to Job:</span></p>
</b><a class="moz-txt-link-freetext"
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/...
class="moz-txt-link-freetext"
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/...
</a></p>
<p><a class="moz-txt-link-freetext"
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/...
<p><b style="font-weight:normal;"
id="docs-internal-guid-5859b7a1-c45f-74ff-f3ff-ccb59b69f04d">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;">Link
to all logs:</span></p>
</b><b style="font-weight:normal;"
id="docs-internal-guid-5859b7a1-c45f-74ff-f3ff-ccb59b69f04d">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;"><a
class="moz-txt-link-freetext"
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/...
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;"><a
class="moz-txt-link-freetext"
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/...
</span></p>
<br>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;">(Relevant)
error snippet from the log: </span></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;"><error></span></p>
</b></p>
<p><br>
</p>
<pre style="color: rgb(0, 0, 0); font-style: normal; font-variant-ligatures:
normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans:
2; text-align: start; text-indent: 0px; text-transform: none; widows: 2; word-spacing:
0px; -webkit-text-stroke-width: 0px; text-decoration-style: initial;
text-decoration-color: initial;">2017-11-15 16:50:07,115-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Loading extension 'internal-authn'
2017-11-15 16:50:07,118-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Extension 'internal-authn' loaded
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config BEGIN
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.profile.name: internal
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authn
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.authz.plugin: internal-authz
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authn
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config END
2017-11-15 16:50:07,119-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Loading extension 'internal-authz'
2017-11-15 16:50:07,120-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Extension 'internal-authz' loaded
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config BEGIN
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authz
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthzExtension
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authz
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config END
2017-11-15 16:50:07,121-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Initializing extension 'internal-authn'
2017-11-15 16:50:07,182-05 ERROR
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Unexpected Exception invoking:
EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2]
2017-11-15 16:50:07,182-05 DEBUG
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Exception:: org.postgresql.util.PSQLException: FATAL: the database system
is shutting down
at
org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:398)
[postgresql.jar:]
at
org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:173)
[postgresql.jar:]
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:64)
[postgresql.jar:]
at
org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:136)
[postgresql.jar:]
at
org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:29)
[postgresql.jar:]
at
org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:21)
[postgresql.jar:]
at
org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:31)
[postgresql.jar:]
at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
[postgresql.jar:]
at org.postgresql.Driver.makeConnection(Driver.java:393) [postgresql.jar:]
at org.postgresql.Driver.connect(Driver.java:267) [postgresql.jar:]
at java.sql.DriverManager.getConnection(DriverManager.java:664) [rt.jar:1.8.0_151]
at java.sql.DriverManager.getConnection(DriverManager.java:247) [rt.jar:1.8.0_151]
at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.DataSourceProvider$1.invoke(DataSourceProvider.java:86)
[ovirt-engine-extension-aaa-jdbc.jar:]
at com.sun.proxy.$Proxy177.getConnection(Unknown Source)
at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.SchemaAwareDataSource.getConnection(SchemaAwareDataSource.java:41)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.ExtensionUtils.checkDbVersion(ExtensionUtils.java:146)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.doInit(AuthnExtension.java:114)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.invoke(AuthnExtension.java:56)
[ovirt-engine-extension-aaa-jdbc.jar:]
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:49)
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:73)
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:109)
at
org.ovirt.engine.core.extensions.mgr.ExtensionsManager.initialize(ExtensionsManager.java:315)
at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.initialize(SsoExtensionsManager.java:91)
at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.<init>(SsoExtensionsManager.java:28)
at
org.ovirt.engine.core.sso.context.SsoContextListener.contextInitialized(SsoContextListener.java:28)
at
io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:205)
at io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:174)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:239)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:99)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[rt.jar:1.8.0_151]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[rt.jar:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[rt.jar:1.8.0_151]
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
2017-11-15 16:50:07,185-05 ERROR [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Error in activating extension
'internal-authn': FATAL: the database system is shutting down
2017-11-15 16:50:07,185-05 DEBUG [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Class: class
org.ovirt.engine.core.extensions.mgr.ExtensionInvokeCommandFailedException</pre>
<p><b style="font-weight:normal;"
id="docs-internal-guid-5859b7a1-c45f-74ff-f3ff-ccb59b69f04d">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span
style="font-size:11pt;font-family:Arial;color:#000000;background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap;"></error></span></p>
</b><br class="Apple-interchange-newline">
</p>
</body>
</html>
--------------D85A420919595D580C076AD7--
4:43 a.m.
Please give it highest priority, we can't let it fail into the weekend.
On Thu, Nov 16, 2017 at 12:40 PM, Dafna Ron <dron(a)redhat.com> wrote:
Hi,
we have a CQ failure in add_dc test. I can see at engine long that we have
an issue with 'extension.aaa.jdbc.binding.api.AuthnExtension'
I don't think that the patch reported was the actual cause of the failure.
Yesterday we were failing on missing package ovirt-cockpit-sso which we
added to our repos. and I think perhaps we now exposed an issue with sso
support which was undiscovered before.
*Link to suspected patches: *
These are the reported patches:
https://gerrit.ovirt.org/#/c/83790/
https://gerrit.ovirt.org/#/c/83779/
* Here is the original patch for the sso support:
https://gerrit.ovirt.org/#/c/82997/ <https://gerrit.ovirt.org/#/c/82997/>
Link to Job: *http://jenkins.ovirt.org/job/ovirt-master_change-queue-
tester/3877/
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/>
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/
*Link to all logs:*
*
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifact/
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifa...
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifact/
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifa...
(Relevant) error snippet from the log: <error> *
2017-11-15 16:50:07,115-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Loading extension 'internal-authn'
2017-11-15 16:50:07,118-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Extension 'internal-authn' loaded
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config BEGIN
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.profile.name: internal
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authn
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.authz.plugin: internal-authz
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authn
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config END
2017-11-15 16:50:07,119-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Loading extension 'internal-authz'
2017-11-15 16:50:07,120-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Extension 'internal-authz' loaded
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config BEGIN
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authz
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthzExtension
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authz
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config END
2017-11-15 16:50:07,121-05 INFO [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Initializing extension 'internal-authn'
2017-11-15 16:50:07,182-05 ERROR
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Unexpected Exception invoking:
EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2]
2017-11-15 16:50:07,182-05 DEBUG
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Exception:: org.postgresql.util.PSQLException: FATAL: the database system
is shutting down
at
org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:398)
[postgresql.jar:]
at
org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:173)
[postgresql.jar:]
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:64)
[postgresql.jar:]
at
org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:136)
[postgresql.jar:]
at
org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:29)
[postgresql.jar:]
at
org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:21)
[postgresql.jar:]
at
org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:31)
[postgresql.jar:]
at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
[postgresql.jar:]
at org.postgresql.Driver.makeConnection(Driver.java:393) [postgresql.jar:]
at org.postgresql.Driver.connect(Driver.java:267) [postgresql.jar:]
at java.sql.DriverManager.getConnection(DriverManager.java:664) [rt.jar:1.8.0_151]
at java.sql.DriverManager.getConnection(DriverManager.java:247) [rt.jar:1.8.0_151]
at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.DataSourceProvider$1.invoke(DataSourceProvider.java:86)
[ovirt-engine-extension-aaa-jdbc.jar:]
at com.sun.proxy.$Proxy177.getConnection(Unknown Source)
at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.SchemaAwareDataSource.getConnection(SchemaAwareDataSource.java:41)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.ExtensionUtils.checkDbVersion(ExtensionUtils.java:146)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.doInit(AuthnExtension.java:114)
[ovirt-engine-extension-aaa-jdbc.jar:]
at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.invoke(AuthnExtension.java:56)
[ovirt-engine-extension-aaa-jdbc.jar:]
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:49)
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:73)
at org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:109)
at
org.ovirt.engine.core.extensions.mgr.ExtensionsManager.initialize(ExtensionsManager.java:315)
at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.initialize(SsoExtensionsManager.java:91)
at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.<init>(SsoExtensionsManager.java:28)
at
org.ovirt.engine.core.sso.context.SsoContextListener.contextInitialized(SsoContextListener.java:28)
at
io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:205)
at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:174)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
at
io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:239)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:99)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[rt.jar:1.8.0_151]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[rt.jar:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[rt.jar:1.8.0_151]
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
2017-11-15 16:50:07,185-05 ERROR [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Error in activating extension
'internal-authn': FATAL: the database system is shutting down
2017-11-15 16:50:07,185-05 DEBUG [org.ovirt.engine.core.extensions.mgr.ExtensionsManager]
(ServerService Thread Pool -- 45) [] Class: class
org.ovirt.engine.core.extensions.mgr.ExtensionInvokeCommandFailedException
*</error>*
_______________________________________________
Devel mailing list
Devel(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/devel
--
Eyal edri
MANAGER
RHV DevOps
EMEA VIRTUALIZATION R&D
Red Hat EMEA <https://www.redhat.com/>
<https://red.ht/sig> TRIED. TESTED. TRUSTED. <https://redhat.com/trusted>
phone: +972-9-7692018
irc: eedri (on #tlv #rhev-dev #rhev-integ)
4:57 a.m.
On Thu, Nov 16, 2017 at 11:43 AM, Eyal Edri <eedri(a)redhat.com> wrote:
Please give it highest priority, we can't let it fail into the
weekend.
On Thu, Nov 16, 2017 at 12:40 PM, Dafna Ron <dron(a)redhat.com> wrote:
> Hi,
>
> we have a CQ failure in add_dc test. I can see at engine long that we
> have an issue with 'extension.aaa.jdbc.binding.api.AuthnExtension'
>
> I don't think that the patch reported was the actual cause of the
> failure. Yesterday we were failing on missing package ovirt-cockpit-sso
> which we added to our repos. and I think perhaps we now exposed an issue
> with sso support which was undiscovered before.
>
>
> *Link to suspected patches: *
>
> These are the reported patches:
>
> https://gerrit.ovirt.org/#/c/83790/
>
> https://gerrit.ovirt.org/#/c/83779/
>
>
>
> * Here is the original patch for the sso support:
> https://gerrit.ovirt.org/#/c/82997/ <https://gerrit.ovirt.org/#/c/82997/>
> Link to Job: *http://jenkins.ovirt.org/job/o
> virt-master_change-queue-tester/3877/
> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/>
>
> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/
>
> *Link to all logs:*
>
>
> *
> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifact/
> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifa...
> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifact/
> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifa...
> (Relevant) error snippet from the log: <error> *
>
>
> 2017-11-15 16:50:07,115-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Loading extension 'internal-authn'
> 2017-11-15 16:50:07,118-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Extension 'internal-authn' loaded
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config BEGIN
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.profile.name: internal
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authn
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.authz.plugin: internal-authz
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authn
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config END
> 2017-11-15 16:50:07,119-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Loading extension 'internal-authz'
> 2017-11-15 16:50:07,120-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Extension 'internal-authz' loaded
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config BEGIN
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authz
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthzExtension
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authz
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config END
> 2017-11-15 16:50:07,121-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Initializing extension 'internal-authn'
> 2017-11-15 16:50:07,182-05 ERROR
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Unexpected Exception invoking:
EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2]
> 2017-11-15 16:50:07,182-05 DEBUG
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Exception:: org.postgresql.util.PSQLException: FATAL: the database system
is shutting down
>
>
This is the main issue, who is stopping PostgreSQL database during engine
startup?
I've looked at /var/log/messages and there are plenty of PostgreSQL
restarts:
Nov 15 16:47:26 lago-basic-suite-master-engine systemd: Starting PostgreSQL
database server...
Nov 15 16:47:26 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:26 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:27 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:47:28 lago-basic-suite-master-engine systemd: Stopping PostgreSQL
database server...
Nov 15 16:47:29 lago-basic-suite-master-engine systemd: Stopped PostgreSQL
database server.
Nov 15 16:47:29 lago-basic-suite-master-engine systemd: Starting PostgreSQL
database server...
Nov 15 16:47:29 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:29 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:30 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:47:30 lago-basic-suite-master-engine systemd: Stopping PostgreSQL
database server...
Nov 15 16:47:31 lago-basic-suite-master-engine systemd: Stopped PostgreSQL
database server.
Nov 15 16:47:31 lago-basic-suite-master-engine systemd: Starting PostgreSQL
database server...
Nov 15 16:47:31 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:31 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:32 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:47:33 lago-basic-suite-master-engine systemd: Stopping PostgreSQL
database server...
Nov 15 16:47:34 lago-basic-suite-master-engine systemd: Stopped PostgreSQL
database server.
Nov 15 16:47:34 lago-basic-suite-master-engine systemd: Starting PostgreSQL
database server...
Nov 15 16:47:34 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:34 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:35 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:50:00 lago-basic-suite-master-engine systemd: Stopping PostgreSQL
database server...
Nov 15 16:50:08 lago-basic-suite-master-engine systemd: Starting PostgreSQL
database server...
So we need to take a look at PostgreSQL logs to see the cause of failures
at
org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:398)
[postgresql.jar:]
> at
org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:173)
[postgresql.jar:]
> at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:64)
[postgresql.jar:]
> at
org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:136)
[postgresql.jar:]
> at
org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:29)
[postgresql.jar:]
> at
org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:21)
[postgresql.jar:]
> at
org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:31)
[postgresql.jar:]
> at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
[postgresql.jar:]
> at org.postgresql.Driver.makeConnection(Driver.java:393) [postgresql.jar:]
> at org.postgresql.Driver.connect(Driver.java:267) [postgresql.jar:]
> at java.sql.DriverManager.getConnection(DriverManager.java:664) [rt.jar:1.8.0_151]
> at java.sql.DriverManager.getConnection(DriverManager.java:247) [rt.jar:1.8.0_151]
> at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.DataSourceProvider$1.invoke(DataSourceProvider.java:86)
[ovirt-engine-extension-aaa-jdbc.jar:]
> at com.sun.proxy.$Proxy177.getConnection(Unknown Source)
> at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.SchemaAwareDataSource.getConnection(SchemaAwareDataSource.java:41)
[ovirt-engine-extension-aaa-jdbc.jar:]
> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.ExtensionUtils.checkDbVersion(ExtensionUtils.java:146)
[ovirt-engine-extension-aaa-jdbc.jar:]
> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.doInit(AuthnExtension.java:114)
[ovirt-engine-extension-aaa-jdbc.jar:]
> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.invoke(AuthnExtension.java:56)
[ovirt-engine-extension-aaa-jdbc.jar:]
> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:49)
> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:73)
> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:109)
> at
org.ovirt.engine.core.extensions.mgr.ExtensionsManager.initialize(ExtensionsManager.java:315)
> at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.initialize(SsoExtensionsManager.java:91)
> at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.<init>(SsoExtensionsManager.java:28)
> at
org.ovirt.engine.core.sso.context.SsoContextListener.contextInitialized(SsoContextListener.java:28)
> at
io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
> at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:205)
> at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:174)
> at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
> at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
> at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
> at
io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:239)
> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:99)
> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[rt.jar:1.8.0_151]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_151]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[rt.jar:1.8.0_151]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[rt.jar:1.8.0_151]
> at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
> at org.jboss.threads.JBossThread.run(JBossThread.java:320)
>
> 2017-11-15 16:50:07,185-05 ERROR
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Error in activating extension 'internal-authn': FATAL: the database system is
shutting down
> 2017-11-15 16:50:07,185-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Class: class
org.ovirt.engine.core.extensions.mgr.ExtensionInvokeCommandFailedException
>
> *</error>*
>
>
> _______________________________________________
> Devel mailing list
> Devel(a)ovirt.org
> http://lists.ovirt.org/mailman/listinfo/devel
>
--
Eyal edri
MANAGER
RHV DevOps
EMEA VIRTUALIZATION R&D
Red Hat EMEA <https://www.redhat.com/>
<https://red.ht/sig> TRIED. TESTED. TRUSTED. <https://redhat.com/trusted>
phone: +972-9-7692018 <+972%209-769-2018>
irc: eedri (on #tlv #rhev-dev #rhev-integ)
--
Martin Perina
Associate Manager, Software Engineering
Red Hat Czech s.r.o.
4:59 a.m.
https://gerrit.ovirt.org/#/c/84231/ ?
On Thu, Nov 16, 2017 at 12:57 PM, Martin Perina <mperina(a)redhat.com> wrote:
On Thu, Nov 16, 2017 at 11:43 AM, Eyal Edri <eedri(a)redhat.com> wrote:
> Please give it highest priority, we can't let it fail into the weekend.
>
> On Thu, Nov 16, 2017 at 12:40 PM, Dafna Ron <dron(a)redhat.com> wrote:
>
>> Hi,
>>
>> we have a CQ failure in add_dc test. I can see at engine long that we
>> have an issue with 'extension.aaa.jdbc.binding.api.AuthnExtension'
>>
>> I don't think that the patch reported was the actual cause of the
>> failure. Yesterday we were failing on missing package ovirt-cockpit-sso
>> which we added to our repos. and I think perhaps we now exposed an issue
>> with sso support which was undiscovered before.
>>
>>
>> *Link to suspected patches: *
>>
>> These are the reported patches:
>>
>> https://gerrit.ovirt.org/#/c/83790/
>>
>> https://gerrit.ovirt.org/#/c/83779/
>>
>>
>>
>> * Here is the original patch for the sso support:
>> https://gerrit.ovirt.org/#/c/82997/ <https://gerrit.ovirt.org/#/c/82997/>
>> Link to Job: *http://jenkins.ovirt.org/job/o
>> virt-master_change-queue-tester/3877/
>> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/>
>>
>> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/
>>
>> *Link to all logs:*
>>
>>
>> *
>> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifact/
>>
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifa...
>> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifact/
>>
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifa...
>> (Relevant) error snippet from the log: <error> *
>>
>>
>> 2017-11-15 16:50:07,115-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Loading extension 'internal-authn'
>> 2017-11-15 16:50:07,118-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Extension 'internal-authn' loaded
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config BEGIN
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.profile.name: internal
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authn
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.authz.plugin: internal-authz
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authn
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config END
>> 2017-11-15 16:50:07,119-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Loading extension 'internal-authz'
>> 2017-11-15 16:50:07,120-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Extension 'internal-authz' loaded
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config BEGIN
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authz
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthzExtension
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authz
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config END
>> 2017-11-15 16:50:07,121-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Initializing extension 'internal-authn'
>> 2017-11-15 16:50:07,182-05 ERROR
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Unexpected Exception invoking:
EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2]
>> 2017-11-15 16:50:07,182-05 DEBUG
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Exception:: org.postgresql.util.PSQLException: FATAL: the database system
is shutting down
>>
>>
This is the main issue, who is stopping PostgreSQL database during engine
startup?
I've looked at /var/log/messages and there are plenty of PostgreSQL
restarts:
Nov 15 16:47:26 lago-basic-suite-master-engine systemd: Starting
PostgreSQL database server...
Nov 15 16:47:26 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:26 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:27 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:47:28 lago-basic-suite-master-engine systemd: Stopping
PostgreSQL database server...
Nov 15 16:47:29 lago-basic-suite-master-engine systemd: Stopped PostgreSQL
database server.
Nov 15 16:47:29 lago-basic-suite-master-engine systemd: Starting
PostgreSQL database server...
Nov 15 16:47:29 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:29 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:30 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:47:30 lago-basic-suite-master-engine systemd: Stopping
PostgreSQL database server...
Nov 15 16:47:31 lago-basic-suite-master-engine systemd: Stopped PostgreSQL
database server.
Nov 15 16:47:31 lago-basic-suite-master-engine systemd: Starting
PostgreSQL database server...
Nov 15 16:47:31 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:31 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:32 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:47:33 lago-basic-suite-master-engine systemd: Stopping
PostgreSQL database server...
Nov 15 16:47:34 lago-basic-suite-master-engine systemd: Stopped PostgreSQL
database server.
Nov 15 16:47:34 lago-basic-suite-master-engine systemd: Starting
PostgreSQL database server...
Nov 15 16:47:34 lago-basic-suite-master-engine postgresql-ctl: LOG:
redirecting log output to logging collector process
Nov 15 16:47:34 lago-basic-suite-master-engine postgresql-ctl: HINT:
Future log output will appear in directory "pg_log".
Nov 15 16:47:35 lago-basic-suite-master-engine systemd: Started PostgreSQL
database server.
Nov 15 16:50:00 lago-basic-suite-master-engine systemd: Stopping
PostgreSQL database server...
Nov 15 16:50:08 lago-basic-suite-master-engine systemd: Starting
PostgreSQL database server...
So we need to take a look at PostgreSQL logs to see the cause of failures
at
org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:398)
[postgresql.jar:]
>> at
org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:173)
[postgresql.jar:]
>> at
org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:64)
[postgresql.jar:]
>> at
org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:136)
[postgresql.jar:]
>> at
org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:29)
[postgresql.jar:]
>> at
org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:21)
[postgresql.jar:]
>> at
org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:31)
[postgresql.jar:]
>> at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
[postgresql.jar:]
>> at org.postgresql.Driver.makeConnection(Driver.java:393) [postgresql.jar:]
>> at org.postgresql.Driver.connect(Driver.java:267) [postgresql.jar:]
>> at java.sql.DriverManager.getConnection(DriverManager.java:664)
[rt.jar:1.8.0_151]
>> at java.sql.DriverManager.getConnection(DriverManager.java:247)
[rt.jar:1.8.0_151]
>> at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.DataSourceProvider$1.invoke(DataSourceProvider.java:86)
[ovirt-engine-extension-aaa-jdbc.jar:]
>> at com.sun.proxy.$Proxy177.getConnection(Unknown Source)
>> at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.SchemaAwareDataSource.getConnection(SchemaAwareDataSource.java:41)
[ovirt-engine-extension-aaa-jdbc.jar:]
>> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.ExtensionUtils.checkDbVersion(ExtensionUtils.java:146)
[ovirt-engine-extension-aaa-jdbc.jar:]
>> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.doInit(AuthnExtension.java:114)
[ovirt-engine-extension-aaa-jdbc.jar:]
>> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.invoke(AuthnExtension.java:56)
[ovirt-engine-extension-aaa-jdbc.jar:]
>> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:49)
>> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:73)
>> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:109)
>> at
org.ovirt.engine.core.extensions.mgr.ExtensionsManager.initialize(ExtensionsManager.java:315)
>> at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.initialize(SsoExtensionsManager.java:91)
>> at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.<init>(SsoExtensionsManager.java:28)
>> at
org.ovirt.engine.core.sso.context.SsoContextListener.contextInitialized(SsoContextListener.java:28)
>> at
io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
>> at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:205)
>> at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:174)
>> at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
>> at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
>> at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
>> at
io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:239)
>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:99)
>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
>> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[rt.jar:1.8.0_151]
>> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_151]
>> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[rt.jar:1.8.0_151]
>> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[rt.jar:1.8.0_151]
>> at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
>> at org.jboss.threads.JBossThread.run(JBossThread.java:320)
>>
>> 2017-11-15 16:50:07,185-05 ERROR
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Error in activating extension 'internal-authn': FATAL: the database system is
shutting down
>> 2017-11-15 16:50:07,185-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Class: class
org.ovirt.engine.core.extensions.mgr.ExtensionInvokeCommandFailedException
>>
>> *</error>*
>>
>>
>> _______________________________________________
>> Devel mailing list
>> Devel(a)ovirt.org
>> http://lists.ovirt.org/mailman/listinfo/devel
>>
>
>
>
> --
>
> Eyal edri
>
>
> MANAGER
>
> RHV DevOps
>
> EMEA VIRTUALIZATION R&D
>
>
> Red Hat EMEA <https://www.redhat.com/>
> <https://red.ht/sig> TRIED. TESTED. TRUSTED.
<https://redhat.com/trusted>
> phone: +972-9-7692018 <+972%209-769-2018>
> irc: eedri (on #tlv #rhev-dev #rhev-integ)
>
--
Martin Perina
Associate Manager, Software Engineering
Red Hat Czech s.r.o.
--
Eyal edri
MANAGER
RHV DevOps
EMEA VIRTUALIZATION R&D
Red Hat EMEA <https://www.redhat.com/>
<https://red.ht/sig> TRIED. TESTED. TRUSTED. <https://redhat.com/trusted>
phone: +972-9-7692018
irc: eedri (on #tlv #rhev-dev #rhev-integ)
5:01 a.m.
this patch you mentioned fixes the problem. Those errors shouldn't occur now
On Thu, 16 Nov 2017 at 12:59 Eyal Edri <eedri(a)redhat.com> wrote:
https://gerrit.ovirt.org/#/c/84231/ ?
On Thu, Nov 16, 2017 at 12:57 PM, Martin Perina <mperina(a)redhat.com>
wrote:
>
>
> On Thu, Nov 16, 2017 at 11:43 AM, Eyal Edri <eedri(a)redhat.com> wrote:
>
>> Please give it highest priority, we can't let it fail into the weekend.
>>
>> On Thu, Nov 16, 2017 at 12:40 PM, Dafna Ron <dron(a)redhat.com> wrote:
>>
>>> Hi,
>>>
>>> we have a CQ failure in add_dc test. I can see at engine long that we
>>> have an issue with 'extension.aaa.jdbc.binding.api.AuthnExtension'
>>>
>>> I don't think that the patch reported was the actual cause of the
>>> failure. Yesterday we were failing on missing package ovirt-cockpit-sso
>>> which we added to our repos. and I think perhaps we now exposed an issue
>>> with sso support which was undiscovered before.
>>>
>>>
>>> *Link to suspected patches: *
>>>
>>> These are the reported patches:
>>>
>>> https://gerrit.ovirt.org/#/c/83790/
>>>
>>> https://gerrit.ovirt.org/#/c/83779/
>>>
>>>
>>>
>>> * Here is the original patch for the sso support:
>>> https://gerrit.ovirt.org/#/c/82997/
<https://gerrit.ovirt.org/#/c/82997/>
>>> Link to Job: *
>>> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/
>>> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/>
>>>
>>> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/
>>>
>>> *Link to all logs:*
>>>
>>>
>>> *
>>> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifact/
>>>
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3877/artifa...
>>> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifact/
>>>
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3878/artifa...
>>> (Relevant) error snippet from the log: <error> *
>>>
>>>
>>> 2017-11-15 16:50:07,115-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Loading extension 'internal-authn'
>>> 2017-11-15 16:50:07,118-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Extension 'internal-authn' loaded
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config BEGIN
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.profile.name: internal
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authn
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.aaa.authn.authz.plugin: internal-authz
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authn
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
>>> 2017-11-15 16:50:07,118-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn]
(ServerService Thread Pool -- 45) [] Config END
>>> 2017-11-15 16:50:07,119-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Loading extension 'internal-authz'
>>> 2017-11-15 16:50:07,120-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Extension 'internal-authz' loaded
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config BEGIN
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.provides:
org.ovirt.engine.api.extensions.aaa.Authz
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.class:
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthzExtension
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.bindings.method: jbossmodule
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] config.datasource.file:
/etc/ovirt-engine/aaa/internal.properties
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.name: internal-authz
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] ovirt.engine.extension.binding.jbossmodule.module:
org.ovirt.engine.extension.aaa.jdbc
>>> 2017-11-15 16:50:07,120-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz]
(ServerService Thread Pool -- 45) [] Config END
>>> 2017-11-15 16:50:07,121-05 INFO
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Initializing extension 'internal-authn'
>>> 2017-11-15 16:50:07,182-05 ERROR
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Unexpected Exception invoking:
EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2]
>>> 2017-11-15 16:50:07,182-05 DEBUG
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (ServerService Thread
Pool -- 45) [] Exception:: org.postgresql.util.PSQLException: FATAL: the database system
is shutting down
>>>
>>>
> This is the main issue, who is stopping PostgreSQL database during
> engine startup?
>
> I've looked at /var/log/messages and there are plenty of PostgreSQL
> restarts:
>
> Nov 15 16:47:26 lago-basic-suite-master-engine systemd: Starting
> PostgreSQL database server...
> Nov 15 16:47:26 lago-basic-suite-master-engine postgresql-ctl: LOG:
> redirecting log output to logging collector process
> Nov 15 16:47:26 lago-basic-suite-master-engine postgresql-ctl: HINT:
> Future log output will appear in directory "pg_log".
> Nov 15 16:47:27 lago-basic-suite-master-engine systemd: Started
> PostgreSQL database server.
> Nov 15 16:47:28 lago-basic-suite-master-engine systemd: Stopping
> PostgreSQL database server...
> Nov 15 16:47:29 lago-basic-suite-master-engine systemd: Stopped
> PostgreSQL database server.
> Nov 15 16:47:29 lago-basic-suite-master-engine systemd: Starting
> PostgreSQL database server...
> Nov 15 16:47:29 lago-basic-suite-master-engine postgresql-ctl: LOG:
> redirecting log output to logging collector process
> Nov 15 16:47:29 lago-basic-suite-master-engine postgresql-ctl: HINT:
> Future log output will appear in directory "pg_log".
> Nov 15 16:47:30 lago-basic-suite-master-engine systemd: Started
> PostgreSQL database server.
> Nov 15 16:47:30 lago-basic-suite-master-engine systemd: Stopping
> PostgreSQL database server...
> Nov 15 16:47:31 lago-basic-suite-master-engine systemd: Stopped
> PostgreSQL database server.
> Nov 15 16:47:31 lago-basic-suite-master-engine systemd: Starting
> PostgreSQL database server...
> Nov 15 16:47:31 lago-basic-suite-master-engine postgresql-ctl: LOG:
> redirecting log output to logging collector process
> Nov 15 16:47:31 lago-basic-suite-master-engine postgresql-ctl: HINT:
> Future log output will appear in directory "pg_log".
> Nov 15 16:47:32 lago-basic-suite-master-engine systemd: Started
> PostgreSQL database server.
> Nov 15 16:47:33 lago-basic-suite-master-engine systemd: Stopping
> PostgreSQL database server...
> Nov 15 16:47:34 lago-basic-suite-master-engine systemd: Stopped
> PostgreSQL database server.
> Nov 15 16:47:34 lago-basic-suite-master-engine systemd: Starting
> PostgreSQL database server...
> Nov 15 16:47:34 lago-basic-suite-master-engine postgresql-ctl: LOG:
> redirecting log output to logging collector process
> Nov 15 16:47:34 lago-basic-suite-master-engine postgresql-ctl: HINT:
> Future log output will appear in directory "pg_log".
> Nov 15 16:47:35 lago-basic-suite-master-engine systemd: Started
> PostgreSQL database server.
> Nov 15 16:50:00 lago-basic-suite-master-engine systemd: Stopping
> PostgreSQL database server...
> Nov 15 16:50:08 lago-basic-suite-master-engine systemd: Starting
> PostgreSQL database server...
>
>
> So we need to take a look at PostgreSQL logs to see the cause of failures
>
> at
org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:398)
[postgresql.jar:]
>>> at
org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:173)
[postgresql.jar:]
>>> at
org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:64)
[postgresql.jar:]
>>> at
org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:136)
[postgresql.jar:]
>>> at
org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:29)
[postgresql.jar:]
>>> at
org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:21)
[postgresql.jar:]
>>> at
org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:31)
[postgresql.jar:]
>>> at
org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
[postgresql.jar:]
>>> at org.postgresql.Driver.makeConnection(Driver.java:393) [postgresql.jar:]
>>> at org.postgresql.Driver.connect(Driver.java:267) [postgresql.jar:]
>>> at java.sql.DriverManager.getConnection(DriverManager.java:664)
[rt.jar:1.8.0_151]
>>> at java.sql.DriverManager.getConnection(DriverManager.java:247)
[rt.jar:1.8.0_151]
>>> at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.DataSourceProvider$1.invoke(DataSourceProvider.java:86)
[ovirt-engine-extension-aaa-jdbc.jar:]
>>> at com.sun.proxy.$Proxy177.getConnection(Unknown Source)
>>> at
org.ovirt.engine.extension.aaa.jdbc.core.datasource.SchemaAwareDataSource.getConnection(SchemaAwareDataSource.java:41)
[ovirt-engine-extension-aaa-jdbc.jar:]
>>> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.ExtensionUtils.checkDbVersion(ExtensionUtils.java:146)
[ovirt-engine-extension-aaa-jdbc.jar:]
>>> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.doInit(AuthnExtension.java:114)
[ovirt-engine-extension-aaa-jdbc.jar:]
>>> at
org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension.invoke(AuthnExtension.java:56)
[ovirt-engine-extension-aaa-jdbc.jar:]
>>> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:49)
>>> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:73)
>>> at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:109)
>>> at
org.ovirt.engine.core.extensions.mgr.ExtensionsManager.initialize(ExtensionsManager.java:315)
>>> at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.initialize(SsoExtensionsManager.java:91)
>>> at
org.ovirt.engine.core.sso.utils.SsoExtensionsManager.<init>(SsoExtensionsManager.java:28)
>>> at
org.ovirt.engine.core.sso.context.SsoContextListener.contextInitialized(SsoContextListener.java:28)
>>> at
io.undertow.servlet.core.ApplicationListeners.contextInitialized(ApplicationListeners.java:187)
>>> at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:205)
>>> at
io.undertow.servlet.core.DeploymentManagerImpl$1.call(DeploymentManagerImpl.java:174)
>>> at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
>>> at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
>>> at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
>>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
>>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
>>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
>>> at
io.undertow.servlet.core.DeploymentManagerImpl.deploy(DeploymentManagerImpl.java:239)
>>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:99)
>>> at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
>>> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[rt.jar:1.8.0_151]
>>> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[rt.jar:1.8.0_151]
>>> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[rt.jar:1.8.0_151]
>>> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[rt.jar:1.8.0_151]
>>> at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
>>> at org.jboss.threads.JBossThread.run(JBossThread.java:320)
>>>
>>> 2017-11-15 16:50:07,185-05 ERROR
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Error in activating extension 'internal-authn': FATAL: the database system is
shutting down
>>> 2017-11-15 16:50:07,185-05 DEBUG
[org.ovirt.engine.core.extensions.mgr.ExtensionsManager] (ServerService Thread Pool -- 45)
[] Class: class
org.ovirt.engine.core.extensions.mgr.ExtensionInvokeCommandFailedException
>>>
>>> *</error>*
>>>
>>>
>>> _______________________________________________
>>> Devel mailing list
>>> Devel(a)ovirt.org
>>> http://lists.ovirt.org/mailman/listinfo/devel
>>>
>>
>>
>>
>> --
>>
>> Eyal edri
>>
>>
>> MANAGER
>>
>> RHV DevOps
>>
>> EMEA VIRTUALIZATION R&D
>>
>>
>> Red Hat EMEA <https://www.redhat.com/>
>> <https://red.ht/sig> TRIED. TESTED. TRUSTED.
>> <https://redhat.com/trusted>
>> phone: +972-9-7692018 <+972%209-769-2018>
>> irc: eedri (on #tlv #rhev-dev #rhev-integ)
>>
>
>
>
> --
> Martin Perina
> Associate Manager, Software Engineering
> Red Hat Czech s.r.o.
>
--
Eyal edri
MANAGER
RHV DevOps
EMEA VIRTUALIZATION R&D
Red Hat EMEA <https://www.redhat.com/>
<https://red.ht/sig> TRIED. TESTED. TRUSTED. <https://redhat.com/trusted>
phone: +972-9-7692018 <+972%209-769-2018>
irc: eedri (on #tlv #rhev-dev #rhev-integ)
2352
days inactive
2352
days old
4 comments
4 participants
participants (4)
-
Dafna Ron -
Eyal Edri -
Martin Perina -
Roy Golan