Re: [ovirt-users] [3.6] API - Internal Server Error

18 Nov 2015

      Hi,

I'm sorry, but I'm not able to find out the cause. Could you please
enable debug log for aaa-jdbc extension using following steps and
send me logs again?

1. Edit file /usr/share/ovirt-engine/share/ovirt-engine/services/ovirt-engine/ovirt-engine.xml.in

2. Locate line that contains following comment:

     <!-- Loggers for the engine: -->

   and append following lines:

     <logger category="org.ovirt.engine.extension.aaa.jdbc">
        <level name="DEBUG"/>
      </logger>

3. Restart ovirt-engine service:

   EL7/Fedora22:
     systemctl restart ovirt-engine

   EL6:
     service ovirt-engine restart

Thanks

Martin Perina

----- Original Message -----
...
From: "Maksim Naumov" <maksim.naumov@hitmeister.de>
To: "Martin Perina" <mperina@redhat.com>
Cc: "users" <users@ovirt.org>
Sent: Wednesday, November 18, 2015 6:15:35 PM
Subject: Re: [ovirt-users] [3.6] API - Internal Server Error
Here is my versions:
Name        : ovirt-engine
Version     : 3.6.0.3
Release     : 1.el7.centos
Name        : ovirt-engine-extension-aaa-jdbc
Version     : 1.0.1
Release     : 1.el7
About the log:
engile.log contains only one line related to this error, you can see it in
the first message. But server.log has a bit more.
Currently, I do the following:
I am running the script which is asking for API every 10 sec for a list of
current running VMs.
After some hours (1-2 hours) the script reporting that there are no VMs.
I went to the API endpoint by myself and everything that I was able to see
is Internal error.
I stopped the script and in a couple of minutes API worked again.
Thank you
SERVER.LOG
2015-11-18 18:13:40,833 ERROR [io.undertow.request] (default task-291)
UT005023: Exception handling request to /api/vms: Class: class
org.ovirt.engine.core.extensions.mgr.ExtensionInvokeCommandFailedException
Input:
{Extkey[name=AAA_AUTHN_CREDENTIALS;type=class
java.lang.String;uuid=AAA_AUTHN_CREDENTIALS[03b96485-4bb5-4592-8167-810a5c909706];]=***,
Extkey[name=EXTENSION_INVOKE_CONTEXT;type=class
org.ovirt.engine.api.extensions.ExtMap;uuid=EXTENSION_INVOKE_CONTEXT[886d2ebb-312a-49ae-9cc3-e1f849834b7d];]={Extkey[name=EXTENSION_INTERFACE_VERSION_MAX;type=class
java.lang.Integer;uuid=EXTENSION_INTERFACE_VERSION_MAX[f4cff49f-2717-4901-8ee9-df362446e3e7];]=0,
Extkey[name=EXTENSION_LICENSE;type=class
java.lang.String;uuid=EXTENSION_LICENSE[8a61ad65-054c-4e31-9c6d-1ca4d60a4c18];]=ASL
2.0, Extkey[name=EXTENSION_NOTES;type=class
java.lang.String;uuid=EXTENSION_NOTES[2da5ad7e-185a-4584-aaff-97f66978e4ea];]=Display
name: "ovirt-engine-extension-aaa-jdbc",
Extkey[name=EXTENSION_HOME_URL;type=class
java.lang.String;uuid=EXTENSION_HOME_URL[4ad7a2f4-f969-42d4-b399-72d192e18304];]=
http://www.ovirt.org, Extkey[name=EXTENSION_LOCALE;type=class
java.lang.String;uuid=EXTENSION_LOCALE[0780b112-0ce0-404a-b85e-8765d778bb29];]=en_US,
Extkey[name=EXTENSION_NAME;type=class
java.lang.String;uuid=EXTENSION_NAME[651381d3-f54f-4547-bf28-b0b01a103184];]="ovirt-engine-extension-aaa-jdbc".authn,
Extkey[name=EXTENSION_INTERFACE_VERSION_MIN;type=class
java.lang.Integer;uuid=EXTENSION_INTERFACE_VERSION_MIN[2b84fc91-305b-497b-a1d7-d961b9d2ce0b];]=0,
Extkey[name=EXTENSION_CONFIGURATION;type=class
java.util.Properties;uuid=EXTENSION_CONFIGURATION[2d48ab72-f0a1-4312-b4ae-5068a226b0fc];]=***,
Extkey[name=EXTENSION_AUTHOR;type=class
java.lang.String;uuid=EXTENSION_AUTHOR[ef242f7a-2dad-4bc5-9aad-e07018b7fbcc];]=The
oVirt Project, Extkey[name=EXTENSION_INSTANCE_NAME;type=class
java.lang.String;uuid=EXTENSION_INSTANCE_NAME[65c67ff6-aeca-4bd5-a245-8674327f011b];]=internal-authn,
Extkey[name=EXTENSION_BUILD_INTERFACE_VERSION;type=class
java.lang.Integer;uuid=EXTENSION_BUILD_INTERFACE_VERSION[cb479e5a-4b23-46f8-aed3-56a4747a8ab7];]=0,
Extkey[name=EXTENSION_CONFIGURATION_SENSITIVE_KEYS;type=interface
java.util.Collection;uuid=EXTENSION_CONFIGURATION_SENSITIVE_KEYS[a456efa1-73ff-4204-9f9b-ebff01e35263];]=[],
Extkey[name=AAA_AUTHN_CAPABILITIES;type=class
java.lang.Long;uuid=AAA_AUTHN_CAPABILITIES[9d16bee3-10fd-46f2-83f9-3d3c54cf258d];]=44,
Extkey[name=EXTENSION_GLOBAL_CONTEXT;type=class
org.ovirt.engine.api.extensions.ExtMap;uuid=EXTENSION_GLOBAL_CONTEXT[9799e72f-7af6-4cf1-bf08-297bc8903676];]=*skip*,
Extkey[name=EXTENSION_VERSION;type=class
java.lang.String;uuid=EXTENSION_VERSION[fe35f6a8-8239-4bdb-ab1a-af9f779ce68c];]="1.0.1",
Extkey[name=EXTENSION_MANAGER_TRACE_LOG;type=interface
org.slf4j.Logger;uuid=EXTENSION_MANAGER_TRACE_LOG[863db666-3ea7-4751-9695-918a3197ad83];]=org.slf4j.impl.Slf4jLogger(org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn),
Extkey[name=EXTENSION_PROVIDES;type=interface
java.util.Collection;uuid=EXTENSION_PROVIDES[8cf373a6-65b5-4594-b828-0e275087de91];]=[org.ovirt.engine.api.extensions.aaa.Authn],
Extkey[name=EXTENSION_CONFIGURATION_FILE;type=class
java.lang.String;uuid=EXTENSION_CONFIGURATION_FILE[4fb0ffd3-983c-4f3f-98ff-9660bd67af6a];]=/etc/ovirt-engine/extensions.d/internal-authn.properties},
Extkey[name=AAA_AUTHN_USER;type=class
java.lang.String;uuid=AAA_AUTHN_USER[1ceaba26-1bdc-4663-a3c6-5d926f9dd8f0];]=admin,
Extkey[name=EXTENSION_INVOKE_COMMAND;type=class
org.ovirt.engine.api.extensions.ExtUUID;uuid=EXTENSION_INVOKE_COMMAND[485778ab-bede-4f1a-b823-77b262a2f28d];]=AAA_AUTHN_AUTHENTICATE_CREDENTIALS[d9605c75-6b43-4b00-b32c-06bdfa80244c]}
Output:
{Extkey[name=EXTENSION_INVOKE_RESULT;type=class
java.lang.Integer;uuid=EXTENSION_INVOKE_RESULT[0909d91d-8bde-40fb-b6c0-099c772ddd4e];]=2}
at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:91)
at
org.ovirt.engine.core.extensions.mgr.ExtensionProxy.invoke(ExtensionProxy.java:109)
at
org.ovirt.engine.core.aaa.filters.BasicAuthenticationFilter.handleCredentials(BasicAuthenticationFilter.java:134)
[aaa.jar:]
at
org.ovirt.engine.core.aaa.filters.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:84)
[aaa.jar:]
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
[undertow-servlet.jar:1.1.5.Final]
at
org.ovirt.engine.core.aaa.filters.SessionValidationFilter.doFilter(SessionValidationFilter.java:77)
[aaa.jar:]
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
[undertow-servlet.jar:1.1.5.Final]
at
org.ovirt.engine.core.aaa.filters.EngineSessionTokenAuthenticationFilter.doFilter(EngineSessionTokenAuthenticationFilter.java:31)
[aaa.jar:]
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
[undertow-servlet.jar:1.1.5.Final]
at
org.ovirt.engine.core.aaa.filters.RestApiSessionValidationFilter.doFilter(RestApiSessionValidationFilter.java:35)
[aaa.jar:]
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
[undertow-servlet.jar:1.1.5.Final]
at
org.ovirt.engine.api.common.security.CSRFProtectionFilter.doFilter(CSRFProtectionFilter.java:111)
[interface-common-jaxrs.jar:]
at
org.ovirt.engine.api.common.security.CSRFProtectionFilter.doFilter(CSRFProtectionFilter.java:102)
[interface-common-jaxrs.jar:]
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
[undertow-servlet.jar:1.1.5.Final]
at
org.ovirt.engine.api.common.security.CORSSupportFilter.doFilter(CORSSupportFilter.java:183)
[interface-common-jaxrs.jar:]
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:85)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
[undertow-servlet.jar:1.1.5.Final]
at
org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:51)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:56)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:70)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[undertow-core.jar:1.1.5.Final]
at
org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[undertow-core.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:261)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:248)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:77)
[undertow-servlet.jar:1.1.5.Final]
at
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:167)
[undertow-servlet.jar:1.1.5.Final]
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:199)
[undertow-core.jar:1.1.5.Final]
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:766)
[undertow-core.jar:1.1.5.Final]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[rt.jar:1.7.0_91]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[rt.jar:1.7.0_91]
at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_91]
On Wed, Nov 18, 2015 at 6:05 PM, Martin Perina <mperina@redhat.com> wrote:
...
Hi,
could you please take a look what versions do you have installed?
rpm -qi ovirt-engine
  rpm -qi ovirt-engine-extension-aaa-jdbc
Could you please also send your server.log and engine.log?
Thanks
Martin Perina
----- Original Message -----
...
From: "Maksim Naumov" <maksim.naumov@hitmeister.de>
To: "users" <users@ovirt.org>
Sent: Wednesday, November 18, 2015 5:56:53 PM
Subject: [ovirt-users] [3.6] API - Internal Server Error
After some time, API stopped work.
When I try to run any request I see only "Internal Server Error" and the
log
like this:
2015-11-18 17:53:05,634 ERROR
[org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension] (default
task-314) [] Unexpected Exception invoking:
AAA_AUTHN_AUTHENTICATE_CREDENTIALS[d9605c75-6b43-4b00-b32c-06bdfa80244c]
How can fix it?
--
Maksim Naumov
Hitmeister GmbH
Softwareentwickler
Habsburgerring 2
50674 Köln
E: maksim.naumov@hitmeister.de
www.hitmeister.de
HRB 59046, Amtsgericht Köln
Geschäftsführer: Dr. Gerald Schönbucher
_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
--
Maksim Naumov
Hitmeister GmbH
Softwareentwickler
Habsburgerring 2
50674 Köln
E: maksim.naumov@hitmeister.de
www.hitmeister.de
HRB 59046, Amtsgericht Köln
Geschäftsführer: Dr. Gerald Schönbucher