ovirt-engine-extension-aaa-ldap-setup failed

24 Oct 2018

      I am having trouble completing the AAA extension setup.  It fails at the end when testing the login flow, if I test the search that part works.
I can confirm that I am able to login to my system using the admin account so there is not a password issue.

I have listed my results below to include log level=finest.  I have also attached a log.  Sugeestions on troubleshooting are appreciated. I am not sure where to start.  Thanks!

          Please provide credentials to test login flow:
          Enter user name: admin
          Enter user password:
[ INFO  ] Executing login sequence...
          Login output:
          2018-10-23 16:43:46,432-05 INFO    ===================================                                                                                        =====================================
          2018-10-23 16:43:46,452-05 INFO    ============================ Initia                                                                                        lization ============================
          2018-10-23 16:43:46,452-05 INFO    ===================================                                                                                        =====================================
          2018-10-23 16:43:46,565-05 INFO    Loading extension 'ldap.cyber-range                                                                                        .lan-authn'
          2018-10-23 16:43:46,668-05 INFO    Extension 'ldap.cyber-range.lan-aut                                                                                        hn' loaded
          2018-10-23 16:43:46,672-05 INFO    Loading extension 'ldap.cyber-range                                                                                        .lan'
          2018-10-23 16:43:46,681-05 INFO    Extension 'ldap.cyber-range.lan' lo                                                                                        aded
          2018-10-23 16:43:46,682-05 INFO    Initializing extension 'ldap.cyber-                                                                                        range.lan-authn'
          2018-10-23 16:43:46,682-05 INFO    [ovirt-engine-extension-aaa-ldap.au                                                                                        thn::ldap.cyber-range.lan-authn] Creating LDAP pool 'authz'
          2018-10-23 16:43:47,236-05 INFO    [ovirt-engine-extension-aaa-ldap.au                                                                                        thn::ldap.cyber-range.lan-authn] LDAP pool 'authz' information: vendor='389 Proj                                                                                        ect' version='389-Directory/1.3.7.5 B2018.269.1826'
          2018-10-23 16:43:47,237-05 INFO    [ovirt-engine-extension-aaa-ldap.au                                                                                        thn::ldap.cyber-range.lan-authn] Creating LDAP pool 'authn'
          2018-10-23 16:43:47,518-05 INFO    [ovirt-engine-extension-aaa-ldap.au                                                                                        thn::ldap.cyber-range.lan-authn] LDAP pool 'authn' information: vendor='389 Proj                                                                                        ect' version='389-Directory/1.3.7.5 B2018.269.1826'
          2018-10-23 16:43:47,518-05 INFO    Extension 'ldap.cyber-range.lan-aut                                                                                        hn' initialized
          2018-10-23 16:43:47,519-05 INFO    Initializing extension 'ldap.cyber-                                                                                        range.lan'
          2018-10-23 16:43:47,520-05 INFO    [ovirt-engine-extension-aaa-ldap.au                                                                                        thz::ldap.cyber-range.lan] Creating LDAP pool 'authz'
          2018-10-23 16:43:47,759-05 INFO    [ovirt-engine-extension-aaa-ldap.au                                                                                        thz::ldap.cyber-range.lan] LDAP pool 'authz' information: vendor='389 Project' v                                                                                        ersion='389-Directory/1.3.7.5 B2018.269.1826'
          2018-10-23 16:43:47,760-05 INFO    [ovirt-engine-extension-aaa-ldap.au                                                                                        thz::ldap.cyber-range.lan] Available Namespaces: [dc=cyber-range,dc=lan]
          2018-10-23 16:43:47,760-05 INFO    Extension 'ldap.cyber-range.lan' in                                                                                        itialized
          2018-10-23 16:43:47,761-05 INFO    Start of enabled extensions list
          2018-10-23 16:43:47,761-05 INFO    Instance name: 'ldap.cyber-range.la                                                                                        n-authn', Extension name: 'ovirt-engine-extension-aaa-ldap.authn', Version: '1.3                                                                                        .7', Notes: 'Display name: ovirt-engine-extension-aaa-ldap-1.3.7-1.el7.centos',                                                                                         License: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Bu                                                                                        ild interface Version: '0',  File: '/tmp/tmprnxgRZ/extensions.d/ldap.cyber-range                                                                                        .lan-authn.properties', Initialized: 'true'
          2018-10-23 16:43:47,761-05 INFO    Instance name: 'ldap.cyber-range.la                                                                                        n', Extension name: 'ovirt-engine-extension-aaa-ldap.authz', Version: '1.3.7', N                                                                                        otes: 'Display name: ovirt-engine-extension-aaa-ldap-1.3.7-1.el7.centos', Licens                                                                                        e: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Build in                                                                                        terface Version: '0',  File: '/tmp/tmprnxgRZ/extensions.d/ldap.cyber-range.lan.p                                                                                        roperties', Initialized: 'true'
          2018-10-23 16:43:47,761-05 INFO    End of enabled extensions list
          2018-10-23 16:43:47,762-05 INFO    ===================================                                                                                        =====================================
          2018-10-23 16:43:47,762-05 INFO    ============================== Exec                                                                                        ution ===============================
          2018-10-23 16:43:47,762-05 INFO    ===================================                                                                                        =====================================
          2018-10-23 16:43:47,762-05 INFO    Iteration: 0
          2018-10-23 16:43:47,763-05 INFO    Profile='ldap.cyber-range.lan' auth                                                                                        n='ldap.cyber-range.lan-authn' authz='ldap.cyber-range.lan' mapping='null'
          2018-10-23 16:43:47,763-05 INFO    API: -->Authn.InvokeCommands.AUTHEN                                                                                        TICATE_CREDENTIALS profile='ldap.cyber-range.lan' user='admin'
          2018-10-23 16:43:47,771-05 INFO    API: <--Authn.InvokeCommands.AUTHEN                                                                                        TICATE_CREDENTIALS profile='ldap.cyber-range.lan' result=CREDENTIALS_INVALID
          2018-10-23 16:43:47,775-05 SEVERE  Authn.Result code is: CREDENTIALS_I                                                                                        NVALID
[ ERROR ] Login sequence failed
          Please investigate details of the failure (search for lines containing                                                                                         SEVERE log level).
          Select test sequence to execute (Done, Abort, Login, Search) [Abort]:Login
          Please provide credentials to test login flow:
          Enter user name: admin
          Enter user password:
[ INFO  ] Executing login sequence...
          Login output:
          2018-10-23 16:44:08,301-05 INFO    ========================================================================
          2018-10-23 16:44:08,320-05 INFO    ============================ Initialization ============================
          2018-10-23 16:44:08,320-05 INFO    ========================================================================
          2018-10-23 16:44:08,346-05 INFO    Loading extension 'ldap.cyber-range.lan-authn'
          2018-10-23 16:44:08,397-05 INFO    Extension 'ldap.cyber-range.lan-authn' loaded
          2018-10-23 16:44:08,401-05 INFO    Loading extension 'ldap.cyber-range.lan'
          2018-10-23 16:44:08,409-05 INFO    Extension 'ldap.cyber-range.lan' loaded
          2018-10-23 16:44:08,409-05 INFO    Initializing extension 'ldap.cyber-range.lan-authn'
          2018-10-23 16:44:08,410-05 INFO    [ovirt-engine-extension-aaa-ldap.authn::ldap.cyber-range.lan-authn] Creating LDAP pool 'authz'
          2018-10-23 16:44:08,914-05 INFO    [ovirt-engine-extension-aaa-ldap.authn::ldap.cyber-range.lan-authn] LDAP pool 'authz' information: vendor='389 Project' version='389-Directory/1.3.7.5 B2018.269.1826'
          2018-10-23 16:44:08,915-05 INFO    [ovirt-engine-extension-aaa-ldap.authn::ldap.cyber-range.lan-authn] Creating LDAP pool 'authn'
          2018-10-23 16:44:09,192-05 INFO    [ovirt-engine-extension-aaa-ldap.authn::ldap.cyber-range.lan-authn] LDAP pool 'authn' information: vendor='389 Project' version='389-Directory/1.3.7.5 B2018.269.1826'
          2018-10-23 16:44:09,193-05 INFO    Extension 'ldap.cyber-range.lan-authn' initialized
          2018-10-23 16:44:09,194-05 INFO    Initializing extension 'ldap.cyber-range.lan'
          2018-10-23 16:44:09,194-05 INFO    [ovirt-engine-extension-aaa-ldap.authz::ldap.cyber-range.lan] Creating LDAP pool 'authz'
          2018-10-23 16:44:09,430-05 INFO    [ovirt-engine-extension-aaa-ldap.authz::ldap.cyber-range.lan] LDAP pool 'authz' information: vendor='389 Project' version='389-Directory/1.3.7.5 B2018.269.1826'
          2018-10-23 16:44:09,431-05 INFO    [ovirt-engine-extension-aaa-ldap.authz::ldap.cyber-range.lan] Available Namespaces: [dc=cyber-range,dc=lan]
          2018-10-23 16:44:09,432-05 INFO    Extension 'ldap.cyber-range.lan' initialized
          2018-10-23 16:44:09,432-05 INFO    Start of enabled extensions list
          2018-10-23 16:44:09,432-05 INFO    Instance name: 'ldap.cyber-range.lan-authn', Extension name: 'ovirt-engine-extension-aaa-ldap.authn', Version: '1.3.7', Notes: 'Display name: ovirt-engine-extension-aaa-ldap-1.3.7-1.el7.centos', License: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Build interface Version: '0',  File: '/tmp/tmprnxgRZ/extensions.d/ldap.cyber-range.lan-authn.properties', Initialized: 'true'
          2018-10-23 16:44:09,433-05 INFO    Instance name: 'ldap.cyber-range.lan', Extension name: 'ovirt-engine-extension-aaa-ldap.authz', Version: '1.3.7', Notes: 'Display name: ovirt-engine-extension-aaa-ldap-1.3.7-1.el7.centos', License: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Build interface Version: '0',  File: '/tmp/tmprnxgRZ/extensions.d/ldap.cyber-range.lan.properties', Initialized: 'true'
          2018-10-23 16:44:09,433-05 INFO    End of enabled extensions list
          2018-10-23 16:44:09,433-05 INFO    ========================================================================
          2018-10-23 16:44:09,433-05 INFO    ============================== Execution ===============================
          2018-10-23 16:44:09,433-05 INFO    ========================================================================
          2018-10-23 16:44:09,433-05 INFO    Iteration: 0
          2018-10-23 16:44:09,434-05 INFO    Profile='ldap.cyber-range.lan' authn='ldap.cyber-range.lan-authn' authz='ldap.cyber-range.lan' mapping='null'
          2018-10-23 16:44:09,434-05 INFO    API: -->Authn.InvokeCommands.AUTHENTICATE_CREDENTIALS profile='ldap.cyber-range.lan' user='admin'
          2018-10-23 16:44:09,443-05 INFO    API: <--Authn.InvokeCommands.AUTHENTICATE_CREDENTIALS profile='ldap.cyber-range.lan' result=CREDENTIALS_INVALID
          2018-10-23 16:44:09,447-05 SEVERE  Authn.Result code is: CREDENTIALS_INVALID
[ ERROR ] Login sequence failed
          Please investigate details of the failure (search for lines containing SEVERE log level).
          Select test sequence to execute (Done, Abort, Login, Search) [Abort]: Abort
[ ERROR ] Failed to execute stage 'Setup validation': Aborted by user
[ INFO  ] Stage: Clean up
          Log file is available at /tmp/ovirt-engine-extension-aaa-ldap-setup-20181023164215-uvjiii.log:
[ INFO  ] Stage: Pre-termination
[ INFO  ] Stage: Termination

[root@engine ~]# ovirt-engine-extensions-tool --log-level=FINEST aaa login-user --user-name=admin --profile=ldap.cyber-range.lan
2018-10-23 17:28:53,690-05 FINE    Version: ovirt-engine-4.2.6.4 ()
2018-10-23 17:28:53,720-05 INFO    ========================================================================
2018-10-23 17:28:53,720-05 INFO    ============================ Initialization ============================
2018-10-23 17:28:53,721-05 INFO    ========================================================================
2018-10-23 17:28:53,722-05 FINE    Loading extension file 'internal-authz.properties'
2018-10-23 17:28:53,751-05 INFO    Loading extension 'internal-authz'
2018-10-23 17:28:53,752-05 FINEST  Invoke Input BEGIN
2018-10-23 17:28:53,754-05 FINEST  {Extkey[name=EXTENSION_INVOKE_COMMAND;type=class org.ovirt.engine.api.extensions.ExtUUID;uuid=EXTENSION_INVOKE_COMMAND[485778ab-bede-4f1a-b823-77b262a2f28d];]=EXTENSION_LOAD[b0f2460e-7971-4a9c-b4e1-c1db1362a47a], 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_GLOBAL_CONTEXT;type=class org.ovirt.engine.api.extensions.ExtMap;uuid=EXTENSION_GLOBAL_CONTEXT[9799e72f-7af6-4cf1-bf08-297bc8903676];]=*skip*, Extkey[name=EXTENSION_MANAGER_TRACE_LOG;type=interface org.slf4j.Logger;uuid=EXTENSION_MANAGER_TRACE_LOG[863db666-3ea7-4751-9695-918a3197ad83];]=org.slf4j.impl.JDK14LoggerAdapter(org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace), Extkey[name=EXTENSION_CONFIGURATION_SENSITIVE_KEYS;type=interface java.util.Collection;uuid=EXTENSION_CONFIGURATION_SENSITIVE_KEYS[a456efa1-73ff-4204-9f9b-ebff01e35263];]=[], Extkey[name=EXTENSION_PROVIDES;type=interface java.util.Collection;uuid=EXTENSION_PROVIDES[8cf373a6-65b5-4594-b828-0e275087de91];]=[org.ovirt.engine.api.extensions.aaa.Authz], Extkey[name=EXTENSION_LOCALE;type=class java.lang.String;uuid=EXTENSION_LOCALE[0780b112-0ce0-404a-b85e-8765d778bb29];]=en_US, 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-authz.properties, Extkey[name=EXTENSION_CONFIGURATION;type=class java.util.Properties;uuid=EXTENSION_CONFIGURATION[2d48ab72-f0a1-4312-b4ae-5068a226b0fc];]=***, 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_INTERFACE_VERSION_MIN;type=class java.lang.Integer;uuid=EXTENSION_INTERFACE_VERSION_MIN[2b84fc91-305b-497b-a1d7-d961b9d2ce0b];]=0, Extkey[name=EXTENSION_INSTANCE_NAME;type=class java.lang.String;uuid=EXTENSION_INSTANCE_NAME[65c67ff6-aeca-4bd5-a245-8674327f011b];]=internal-authz}}
2018-10-23 17:28:53,755-05 FINEST  Invoke Input END
2018-10-23 17:28:53,759-05 FINEST  Invoke Output BEGIN
2018-10-23 17:28:53,759-05 FINEST  {Extkey[name=AAA_AUTHZ_STATUS;type=class java.lang.Integer;uuid=AAA_AUTHZ_STATUS[566f0ba5-8329-4de1-952a-7a81e4bedd3e];]=0, Extkey[name=EXTENSION_INVOKE_RESULT;type=class java.lang.Integer;uuid=EXTENSION_INVOKE_RESULT[0909d91d-8bde-40fb-b6c0-099c772ddd4e];]=0}
2018-10-23 17:28:53,759-05 FINEST  Invoke Output END
2018-10-23 17:28:53,760-05 INFO    Extension 'internal-authz' loaded
2018-10-23 17:28:53,760-05 FINE    Config BEGIN
2018-10-23 17:28:53,760-05 FINE    ovirt.engine.extension.provides: org.ovirt.engine.api.extensions.aaa.Authz
2018-10-23 17:28:53,761-05 FINE    ovirt.engine.extension.binding.jbossmodule.class: org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthzExtension
2018-10-23 17:28:53,761-05 FINE    ovirt.engine.extension.bindings.method: jbossmodule
2018-10-23 17:28:53,761-05 FINE    config.datasource.file: /etc/ovirt-engine/aaa/internal.properties
2018-10-23 17:28:53,761-05 FINE    ovirt.engine.extension.name: internal-authz
2018-10-23 17:28:53,762-05 FINE    ovirt.engine.extension.binding.jbossmodule.module: org.ovirt.engine.extension.aaa.jdbc
2018-10-23 17:28:53,762-05 FINE    Config END
2018-10-23 17:28:53,762-05 FINE    Loading extension file 'internal-authn.properties'
2018-10-23 17:28:53,763-05 INFO    Loading extension 'internal-authn'
2018-10-23 17:28:53,763-05 FINEST  Invoke Input BEGIN
2018-10-23 17:28:53,764-05 FINEST  {Extkey[name=EXTENSION_INVOKE_COMMAND;type=class org.ovirt.engine.api.extensions.ExtUUID;uuid=EXTENSION_INVOKE_COMMAND[485778ab-bede-4f1a-b823-77b262a2f28d];]=EXTENSION_LOAD[b0f2460e-7971-4a9c-b4e1-c1db1362a47a], 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_GLOBAL_CONTEXT;type=class org.ovirt.engine.api.extensions.ExtMap;uuid=EXTENSION_GLOBAL_CONTEXT[9799e72f-7af6-4cf1-bf08-297bc8903676];]=*skip*, Extkey[name=EXTENSION_MANAGER_TRACE_LOG;type=interface org.slf4j.Logger;uuid=EXTENSION_MANAGER_TRACE_LOG[863db666-3ea7-4751-9695-918a3197ad83];]=org.slf4j.impl.JDK14LoggerAdapter(org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace), Extkey[name=EXTENSION_CONFIGURATION_SENSITIVE_KEYS;type=interface java.util.Collection;uuid=EXTENSION_CONFIGURATION_SENSITIVE_KEYS[a456efa1-73ff-4204-9f9b-ebff01e35263];]=[], 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_LOCALE;type=class java.lang.String;uuid=EXTENSION_LOCALE[0780b112-0ce0-404a-b85e-8765d778bb29];]=en_US, 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=EXTENSION_CONFIGURATION;type=class java.util.Properties;uuid=EXTENSION_CONFIGURATION[2d48ab72-f0a1-4312-b4ae-5068a226b0fc];]=***, 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_INTERFACE_VERSION_MIN;type=class java.lang.Integer;uuid=EXTENSION_INTERFACE_VERSION_MIN[2b84fc91-305b-497b-a1d7-d961b9d2ce0b];]=0, Extkey[name=EXTENSION_INSTANCE_NAME;type=class java.lang.String;uuid=EXTENSION_INSTANCE_NAME[65c67ff6-aeca-4bd5-a245-8674327f011b];]=internal-authn}}
2018-10-23 17:28:53,765-05 FINEST  Invoke Input END
2018-10-23 17:28:53,766-05 FINEST  Invoke Output BEGIN
2018-10-23 17:28:53,766-05 FINEST  {Extkey[name=EXTENSION_INVOKE_RESULT;type=class java.lang.Integer;uuid=EXTENSION_INVOKE_RESULT[0909d91d-8bde-40fb-b6c0-099c772ddd4e];]=0}
2018-10-23 17:28:53,766-05 FINEST  Invoke Output END
2018-10-23 17:28:53,766-05 INFO    Extension 'internal-authn' loaded
2018-10-23 17:28:53,767-05 FINE    Config BEGIN
2018-10-23 17:28:53,767-05 FINE    ovirt.engine.aaa.authn.profile.name: internal
2018-10-23 17:28:53,767-05 FINE    ovirt.engine.extension.provides: org.ovirt.engine.api.extensions.aaa.Authn
2018-10-23 17:28:53,767-05 FINE    ovirt.engine.extension.binding.jbossmodule.class: org.ovirt.engine.extension.aaa.jdbc.binding.api.AuthnExtension
2018-10-23 17:28:53,767-05 FINE    ovirt.engine.aaa.authn.authz.plugin: internal-authz
2018-10-23 17:28:53,768-05 FINE    ovirt.engine.extension.bindings.method: jbossmodule
2018-10-23 17:28:53,768-05 FINE    config.datasource.file: /etc/ovirt-engine/aaa/internal.properties
2018-10-23 17:28:53,768-05 FINE    ovirt.engine.extension.name: internal-authn
2018-10-23 17:28:53,768-05 FINE    ovirt.engine.extension.binding.jbossmodule.module: org.ovirt.engine.extension.aaa.jdbc
2018-10-23 17:28:53,768-05 FINE    Config END
2018-10-23 17:28:53,769-05 INFO    Initializing extension 'internal-authz'
2018-10-23 17:28:53,769-05 FINEST  Invoke Input BEGIN
2018-10-23 17:28:53,771-05 FINEST  {Extkey[name=EXTENSION_INVOKE_COMMAND;type=class org.ovirt.engine.api.extensions.ExtUUID;uuid=EXTENSION_INVOKE_COMMAND[485778ab-bede-4f1a-b823-77b262a2f28d];]=EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2], Extkey[name=EXTENSION_INVOKE_CONTEXT;type=class org.ovirt.engine.api.extensions.ExtMap;uuid=EXTENSION_INVOKE_CONTEXT[886d2ebb-312a-49ae-9cc3-e1f849834b7d];]={Extkey[name=AAA_AUTHZ_AVAILABLE_NAMESPACES;type=interface java.util.Collection;uuid=AAA_AUTHZ_AVAILABLE_NAMESPACES[6dffa34c-955f-486a-bd35-0a272b45a711];]=[*], Extkey[name=EXTENSION_LICENSE;type=class java.lang.String;uuid=EXTENSION_LICENSE[8a61ad65-054c-4e31-9c6d-1ca4d60a4c18];]=ASL 2.0, 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_NAME;type=class java.lang.String;uuid=EXTENSION_NAME[651381d3-f54f-4547-bf28-b0b01a103184];]="ovirt-engine-extension-aaa-jdbc".authz, Extkey[name=EXTENSION_MANAGER_TRACE_LOG;type=interface org.slf4j.Logger;uuid=EXTENSION_MANAGER_TRACE_LOG[863db666-3ea7-4751-9695-918a3197ad83];]=org.slf4j.impl.JDK14LoggerAdapter(org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authz.internal-authz), Extkey[name=EXTENSION_CONFIGURATION_SENSITIVE_KEYS;type=interface java.util.Collection;uuid=EXTENSION_CONFIGURATION_SENSITIVE_KEYS[a456efa1-73ff-4204-9f9b-ebff01e35263];]=[], Extkey[name=EXTENSION_VERSION;type=class java.lang.String;uuid=EXTENSION_VERSION[fe35f6a8-8239-4bdb-ab1a-af9f779ce68c];]="1.1.7_master", Extkey[name=EXTENSION_PROVIDES;type=interface java.util.Collection;uuid=EXTENSION_PROVIDES[8cf373a6-65b5-4594-b828-0e275087de91];]=[org.ovirt.engine.api.extensions.aaa.Authz], Extkey[name=EXTENSION_AUTHOR;type=class java.lang.String;uuid=EXTENSION_AUTHOR[ef242f7a-2dad-4bc5-9aad-e07018b7fbcc];]=The oVirt Project, Extkey[name=EXTENSION_LOCALE;type=class java.lang.String;uuid=EXTENSION_LOCALE[0780b112-0ce0-404a-b85e-8765d778bb29];]=en_US, 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-authz.properties, 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_CONFIGURATION;type=class java.util.Properties;uuid=EXTENSION_CONFIGURATION[2d48ab72-f0a1-4312-b4ae-5068a226b0fc];]=***, Extkey[name=EXTENSION_INTERFACE_VERSION_MAX;type=class java.lang.Integer;uuid=EXTENSION_INTERFACE_VERSION_MAX[f4cff49f-2717-4901-8ee9-df362446e3e7];]=0, Extkey[name=AAA_AUTHZ_QUERY_MAX_FILTER_SIZE;type=class java.lang.Integer;uuid=AAA_AUTHZ_QUERY_MAX_FILTER_SIZE[2eb1f541-0f65-44a1-a6e3-014e247595f5];]=100, 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_INSTANCE_NAME;type=class java.lang.String;uuid=EXTENSION_INSTANCE_NAME[65c67ff6-aeca-4bd5-a245-8674327f011b];]=internal-authz, Extkey[name=AAA_AUTHZ_CAPABILITIES;type=class java.lang.Long;uuid=AAA_AUTHZ_CAPABILITIES[6106d1fb-9291-4351-a947-b897b9540a23];]=1, 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_NOTES;type=class java.lang.String;uuid=EXTENSION_NOTES[2da5ad7e-185a-4584-aaff-97f66978e4ea];]=Display name: "ovirt-engine-extension-aaa-jdbc"}}
2018-10-23 17:28:53,771-05 FINEST  Invoke Input END
2018-10-23 17:28:53,832-05 FINEST  cursor for: SELECT COUNT(script) AS count FROM schema_version WHERE script = $JcvsJ$upgrade/01_00_0060_missing_indexes.sql$JcvsJ$
2018-10-23 17:28:53,846-05 FINEST  Invoke Output BEGIN
2018-10-23 17:28:53,846-05 FINEST  {Extkey[name=AAA_AUTHZ_STATUS;type=class java.lang.Integer;uuid=AAA_AUTHZ_STATUS[566f0ba5-8329-4de1-952a-7a81e4bedd3e];]=0, Extkey[name=EXTENSION_INVOKE_RESULT;type=class java.lang.Integer;uuid=EXTENSION_INVOKE_RESULT[0909d91d-8bde-40fb-b6c0-099c772ddd4e];]=0}
2018-10-23 17:28:53,846-05 FINEST  Invoke Output END
2018-10-23 17:28:53,847-05 INFO    Extension 'internal-authz' initialized
2018-10-23 17:28:53,847-05 FINE    Extension 'internal-authz' initialized
2018-10-23 17:28:53,847-05 INFO    Initializing extension 'internal-authn'
2018-10-23 17:28:53,848-05 FINEST  Invoke Input BEGIN
2018-10-23 17:28:53,849-05 FINEST  {Extkey[name=EXTENSION_INVOKE_COMMAND;type=class org.ovirt.engine.api.extensions.ExtUUID;uuid=EXTENSION_INVOKE_COMMAND[485778ab-bede-4f1a-b823-77b262a2f28d];]=EXTENSION_INITIALIZE[e5ae1b7f-9104-4f23-a444-7b9175ff68d2], 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_LICENSE;type=class java.lang.String;uuid=EXTENSION_LICENSE[8a61ad65-054c-4e31-9c6d-1ca4d60a4c18];]=ASL 2.0, 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_NAME;type=class java.lang.String;uuid=EXTENSION_NAME[651381d3-f54f-4547-bf28-b0b01a103184];]="ovirt-engine-extension-aaa-jdbc".authn, Extkey[name=EXTENSION_MANAGER_TRACE_LOG;type=interface org.slf4j.Logger;uuid=EXTENSION_MANAGER_TRACE_LOG[863db666-3ea7-4751-9695-918a3197ad83];]=org.slf4j.impl.JDK14LoggerAdapter(org.ovirt.engine.core.extensions.mgr.ExtensionsManager.trace."ovirt-engine-extension-aaa-jdbc".authn.internal-authn), Extkey[name=EXTENSION_CONFIGURATION_SENSITIVE_KEYS;type=interface java.util.Collection;uuid=EXTENSION_CONFIGURATION_SENSITIVE_KEYS[a456efa1-73ff-4204-9f9b-ebff01e35263];]=[], Extkey[name=EXTENSION_VERSION;type=class java.lang.String;uuid=EXTENSION_VERSION[fe35f6a8-8239-4bdb-ab1a-af9f779ce68c];]="1.1.7_master", 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_AUTHOR;type=class java.lang.String;uuid=EXTENSION_AUTHOR[ef242f7a-2dad-4bc5-9aad-e07018b7fbcc];]=The oVirt Project, Extkey[name=EXTENSION_LOCALE;type=class java.lang.String;uuid=EXTENSION_LOCALE[0780b112-0ce0-404a-b85e-8765d778bb29];]=en_US, 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=EXTENSION_HOME_URL;type=class java.lang.String;uuid=EXTENSION_HOME_URL[4ad7a2f4-f969-42d4-b399-72d192e18304];]=http://www.ovirt.org, Extkey[name=EXTENSION_CONFIGURATION;type=class java.util.Properties;uuid=EXTENSION_CONFIGURATION[2d48ab72-f0a1-4312-b4ae-5068a226b0fc];]=***, 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_INTERFACE_VERSION_MIN;type=class java.lang.Integer;uuid=EXTENSION_INTERFACE_VERSION_MIN[2b84fc91-305b-497b-a1d7-d961b9d2ce0b];]=0, 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=AAA_AUTHN_CAPABILITIES;type=class java.lang.Long;uuid=AAA_AUTHN_CAPABILITIES[9d16bee3-10fd-46f2-83f9-3d3c54cf258d];]=44, Extkey[name=EXTENSION_NOTES;type=class java.lang.String;uuid=EXTENSION_NOTES[2da5ad7e-185a-4584-aaff-97f66978e4ea];]=Display name: "ovirt-engine-extension-aaa-jdbc"}}
2018-10-23 17:28:53,849-05 FINEST  Invoke Input END
2018-10-23 17:28:53,856-05 FINEST  cursor for: SELECT COUNT(script) AS count FROM schema_version WHERE script = $cnCUr$upgrade/01_00_0060_missing_indexes.sql$cnCUr$
2018-10-23 17:28:53,859-05 FINEST  Invoke Output BEGIN
2018-10-23 17:28:53,859-05 FINEST  {Extkey[name=EXTENSION_INVOKE_RESULT;type=class java.lang.Integer;uuid=EXTENSION_INVOKE_RESULT[0909d91d-8bde-40fb-b6c0-099c772ddd4e];]=0}
2018-10-23 17:28:53,859-05 FINEST  Invoke Output END
2018-10-23 17:28:53,859-05 INFO    Extension 'internal-authn' initialized
2018-10-23 17:28:53,860-05 FINE    Extension 'internal-authn' initialized
2018-10-23 17:28:53,860-05 INFO    Start of enabled extensions list
2018-10-23 17:28:53,860-05 INFO    Instance name: 'internal-authn', Extension name: '"ovirt-engine-extension-aaa-jdbc".authn', Version: '"1.1.7_master"', Notes: 'Display name: "ovirt-engine-extension-aaa-jdbc"', License: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Build interface Version: '0',  File: '/etc/ovirt-engine/extensions.d/internal-authn.properties', Initialized: 'true'
2018-10-23 17:28:53,860-05 INFO    Instance name: 'internal-authz', Extension name: '"ovirt-engine-extension-aaa-jdbc".authz', Version: '"1.1.7_master"', Notes: 'Display name: "ovirt-engine-extension-aaa-jdbc"', License: 'ASL 2.0', Home: 'http://www.ovirt.org', Author 'The oVirt Project', Build interface Version: '0',  File: '/etc/ovirt-engine/extensions.d/internal-authz.properties', Initialized: 'true'
2018-10-23 17:28:53,861-05 INFO    End of enabled extensions list
2018-10-23 17:28:53,861-05 INFO    ========================================================================
2018-10-23 17:28:53,861-05 INFO    ============================== Execution ===============================
2018-10-23 17:28:53,861-05 INFO    ========================================================================
2018-10-23 17:28:53,861-05 INFO    Iteration: 0
2018-10-23 17:28:53,863-05 SEVERE  Profile 'ldap.cyber-range.lan' not found
2018-10-23 17:28:53,863-05 FINE    Exception:
java.lang.IllegalArgumentException: Profile 'ldap.cyber-range.lan' not found
        at org.ovirt.engine.exttool.aaa.AAAServiceImpl.getExtensionByProfile(AAAServiceImpl.java:549)
        at org.ovirt.engine.exttool.aaa.AAAServiceImpl.access$1200(AAAServiceImpl.java:37)
        at org.ovirt.engine.exttool.aaa.AAAServiceImpl$AAAProfile.<init>(AAAServiceImpl.java:838)
        at org.ovirt.engine.exttool.aaa.AAAServiceImpl$Action.lambda$static$3(AAAServiceImpl.java:154)
        at org.ovirt.engine.exttool.aaa.AAAServiceImpl$Action.execute(AAAServiceImpl.java:417)
        at org.ovirt.engine.exttool.aaa.AAAServiceImpl.run(AAAServiceImpl.java:686)
        at org.ovirt.engine.exttool.core.ExtensionsToolExecutor.main(ExtensionsToolExecutor.java:120)
        at org.jboss.modules.Module.run(Module.java:352)
        at org.jboss.modules.Module.run(Module.java:320)
        at org.jboss.modules.Main.main(Main.java:593)

2018-10-23 17:28:53,864-05 FINE    Exiting with status '1'

Jeremy Tourville

Ondra Machacek

tags

participants (2)