Installation (from scratch, no migration) gives "no user found"

heidivanparys commented 2 years ago

Trying to perform an installation from scratch (thus no migration) gives "no user found", see also screenshot and extract from log file below.

Information about the deployment:

Ubuntu v20.04LTS
Java 1.8.0_292-8u292-b10-0ubuntu1~20.04-b10
Apache Tomcat 8.5.70
Apache Solr 8.9.0
Apache Server installed, but the application on the Tomcat is accessed directly
Apache Shiro is used
the code has been modified at some points, see https://github.com/heidivanparys/re3gistry/commits/additional_changes_2, mainly to
- use Oracle instead of PostgreSQL
- add trace and debug logging
- fix some issues encountered earlier, see also previously created pull requests
- to make more properties configurable via Maven profiles

Investigation so far:

The code sets an attribute with the newly created administrator user on the session:

https://github.com/ec-jrc/re3gistry/blob/79f806053066cfa1fb1636ce34b64912004ccb32/sources/Re3gistry2JavaAPI/src/main/java/eu/europa/ec/re3gistry2/javaapi/handler/RegInstallationStep3Handler.java#L62

but in the next step, no user is found on the session (because it is in fact another session?), resulting in an error:

https://github.com/ec-jrc/re3gistry/blob/79f806053066cfa1fb1636ce34b64912004ccb32/sources/Re3gistry2JavaAPI/src/main/java/eu/europa/ec/re3gistry2/javaapi/handler/RegInstallationStepCleanInstallationProcessHandler.java#L75-L79

Any help on how to solve this issue would be greatly appreciated.

[TRACE] 2021-11-10 00:18:40.379 [http-nio-8080-exec-173] [controller.LoadSalt.doFilter:52] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[TRACE] 2021-11-10 00:18:40.392 [http-nio-8080-exec-173] [controller.LoadSalt.doFilter:60] - Creating CSRF prevention salt cache
[TRACE] 2021-11-10 00:18:40.415 [http-nio-8080-exec-173] [controller.LoadSalt.doFilter:69] - Generate the salt, store it in the users cache, and add it to the current request
[TRACE] 2021-11-10 00:18:40.419 [http-nio-8080-exec-173] [controller.ValidateSalt.doFilter:50] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[DEBUG] 2021-11-10 00:18:40.419 [http-nio-8080-exec-173] [controller.ValidateSalt.doFilter:58] - Validating that the salt is in the cache
[DEBUG] 2021-11-10 00:18:40.419 [http-nio-8080-exec-173] [controller.ValidateSalt.doFilter:66] - Salt is in cache, thus moving on
[TRACE] 2021-11-10 00:18:40.432 [http-nio-8080-exec-173] [controller.Install.processRequest:54] - Start processing request in eu.europa.ec.re3gistry2.web.controller.Install
[DEBUG] 2021-11-10 00:18:40.433 [http-nio-8080-exec-173] [utility.Configuration.initServlet:162] - Start initialising servlet
[DEBUG] 2021-11-10 00:18:40.433 [http-nio-8080-exec-173] [utility.Configuration.initServlet:180] - Proceed initialising servlet
[TRACE] 2021-11-10 00:18:40.433 [http-nio-8080-exec-173] [utility.Configuration.initServlet:183] - Initialise properties
[TRACE] 2021-11-10 00:18:40.433 [http-nio-8080-exec-173] [utility.Configuration.initServlet:188] - Initialise localisation
[TRACE] 2021-11-10 00:18:40.433 [http-nio-8080-exec-173] [utility.Configuration.initServlet:193] - Initialise available languages in session if needed
[DEBUG] 2021-11-10 00:18:40.434 [http-nio-8080-exec-173] [utility.Configuration.initServlet:205] - Current page name=/install
[TRACE] 2021-11-10 00:18:40.434 [http-nio-8080-exec-173] [utility.Configuration.initServlet:213] - No user found in the session, checking user
[TRACE] 2021-11-10 00:18:42.327 [http-nio-8080-exec-173] [utility.UserHelper.checkUser:81] - loginType=SHIRO
[DEBUG] 2021-11-10 00:18:42.328 [http-nio-8080-exec-173] [utility.Configuration.initServlet:221] - No user found
[TRACE] 2021-11-10 00:18:42.341 [http-nio-8080-exec-173] [controller.Install.processRequest:64] - Session id: 88884FC5F0ECD8961C899BB7B3C47123
[DEBUG] 2021-11-10 00:18:42.342 [http-nio-8080-exec-173] [controller.Install.processRequest:74] - install step = 1
[TRACE] 2021-11-10 00:18:48.101 [http-nio-8080-exec-174] [controller.LoadSalt.doFilter:52] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[TRACE] 2021-11-10 00:18:48.102 [http-nio-8080-exec-174] [controller.LoadSalt.doFilter:60] - Creating CSRF prevention salt cache
[TRACE] 2021-11-10 00:18:48.102 [http-nio-8080-exec-174] [controller.LoadSalt.doFilter:69] - Generate the salt, store it in the users cache, and add it to the current request
[TRACE] 2021-11-10 00:18:48.103 [http-nio-8080-exec-174] [controller.ValidateSalt.doFilter:50] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[DEBUG] 2021-11-10 00:18:48.103 [http-nio-8080-exec-174] [controller.ValidateSalt.doFilter:58] - Validating that the salt is in the cache
[DEBUG] 2021-11-10 00:18:48.103 [http-nio-8080-exec-174] [controller.ValidateSalt.doFilter:66] - Salt is in cache, thus moving on
[TRACE] 2021-11-10 00:18:48.104 [http-nio-8080-exec-174] [controller.Install.processRequest:54] - Start processing request in eu.europa.ec.re3gistry2.web.controller.Install
[DEBUG] 2021-11-10 00:18:48.104 [http-nio-8080-exec-174] [utility.Configuration.initServlet:162] - Start initialising servlet
[DEBUG] 2021-11-10 00:18:48.104 [http-nio-8080-exec-174] [utility.Configuration.initServlet:180] - Proceed initialising servlet
[TRACE] 2021-11-10 00:18:48.105 [http-nio-8080-exec-174] [utility.Configuration.initServlet:183] - Initialise properties
[TRACE] 2021-11-10 00:18:48.105 [http-nio-8080-exec-174] [utility.Configuration.initServlet:188] - Initialise localisation
[TRACE] 2021-11-10 00:18:48.105 [http-nio-8080-exec-174] [utility.Configuration.initServlet:193] - Initialise available languages in session if needed
[DEBUG] 2021-11-10 00:18:48.105 [http-nio-8080-exec-174] [utility.Configuration.initServlet:205] - Current page name=/install
[TRACE] 2021-11-10 00:18:48.106 [http-nio-8080-exec-174] [utility.Configuration.initServlet:213] - No user found in the session, checking user
[TRACE] 2021-11-10 00:18:48.132 [http-nio-8080-exec-174] [utility.UserHelper.checkUser:81] - loginType=SHIRO
[DEBUG] 2021-11-10 00:18:48.132 [http-nio-8080-exec-174] [utility.Configuration.initServlet:221] - No user found
[TRACE] 2021-11-10 00:18:48.146 [http-nio-8080-exec-174] [controller.Install.processRequest:64] - Session id: 4C933354ED0B8B9D1022ECFA9360356C
[DEBUG] 2021-11-10 00:18:48.222 [http-nio-8080-exec-174] [controller.Install.processRequest:74] - install step = 2
[TRACE] 2021-11-10 00:19:01.423 [http-nio-8080-exec-170] [controller.LoadSalt.doFilter:52] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[TRACE] 2021-11-10 00:19:01.423 [http-nio-8080-exec-170] [controller.LoadSalt.doFilter:60] - Creating CSRF prevention salt cache
[TRACE] 2021-11-10 00:19:01.423 [http-nio-8080-exec-170] [controller.LoadSalt.doFilter:69] - Generate the salt, store it in the users cache, and add it to the current request
[TRACE] 2021-11-10 00:19:01.424 [http-nio-8080-exec-170] [controller.ValidateSalt.doFilter:50] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[DEBUG] 2021-11-10 00:19:01.424 [http-nio-8080-exec-170] [controller.ValidateSalt.doFilter:58] - Validating that the salt is in the cache
[DEBUG] 2021-11-10 00:19:01.424 [http-nio-8080-exec-170] [controller.ValidateSalt.doFilter:66] - Salt is in cache, thus moving on
[TRACE] 2021-11-10 00:19:01.425 [http-nio-8080-exec-170] [controller.Install.processRequest:54] - Start processing request in eu.europa.ec.re3gistry2.web.controller.Install
[DEBUG] 2021-11-10 00:19:01.425 [http-nio-8080-exec-170] [utility.Configuration.initServlet:162] - Start initialising servlet
[DEBUG] 2021-11-10 00:19:01.425 [http-nio-8080-exec-170] [utility.Configuration.initServlet:180] - Proceed initialising servlet
[TRACE] 2021-11-10 00:19:01.426 [http-nio-8080-exec-170] [utility.Configuration.initServlet:183] - Initialise properties
[TRACE] 2021-11-10 00:19:01.426 [http-nio-8080-exec-170] [utility.Configuration.initServlet:188] - Initialise localisation
[TRACE] 2021-11-10 00:19:01.426 [http-nio-8080-exec-170] [utility.Configuration.initServlet:193] - Initialise available languages in session if needed
[DEBUG] 2021-11-10 00:19:01.426 [http-nio-8080-exec-170] [utility.Configuration.initServlet:205] - Current page name=/install
[TRACE] 2021-11-10 00:19:01.427 [http-nio-8080-exec-170] [utility.Configuration.initServlet:213] - No user found in the session, checking user
[TRACE] 2021-11-10 00:19:01.455 [http-nio-8080-exec-170] [utility.UserHelper.checkUser:81] - loginType=SHIRO
[DEBUG] 2021-11-10 00:19:01.455 [http-nio-8080-exec-170] [utility.Configuration.initServlet:221] - No user found
[TRACE] 2021-11-10 00:19:01.467 [http-nio-8080-exec-170] [controller.Install.processRequest:64] - Session id: A2A11E01D46DBD7F3450BD9599F1AC39
[DEBUG] 2021-11-10 00:19:01.467 [http-nio-8080-exec-170] [controller.Install.processRequest:74] - install step = 3
[DEBUG] 2021-11-10 00:19:01.482 [http-nio-8080-exec-170] [handler.RegInstallationHandler.createRegUser:602] - Creating new administrator user
[DEBUG] 2021-11-10 00:19:01.487 [http-nio-8080-exec-170] [handler.RegInstallationHandler.createRegUser:622] - Administrator user eu.europa.ec.re3gistry2.model.RegUser[ uuid=4ea865adface3494971c6deb5ab1deac ] created
[DEBUG] 2021-11-10 00:19:01.608 [http-nio-8080-exec-170] [handler.RegInstallationHandler.createRegUser:631] - Administrator user eu.europa.ec.re3gistry2.model.RegUser[ uuid=4ea865adface3494971c6deb5ab1deac ] persisted and committed
[DEBUG] 2021-11-10 00:19:01.721 [http-nio-8080-exec-170] [handler.RegInstallationStep3Handler.addUser:64] - Set user eu.europa.ec.re3gistry2.model.RegUser[ uuid=4ea865adface3494971c6deb5ab1deac ] as an attribute on the session
[TRACE] 2021-11-10 00:19:04.363 [http-nio-8080-exec-164] [controller.LoadSalt.doFilter:52] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[TRACE] 2021-11-10 00:19:04.363 [http-nio-8080-exec-164] [controller.LoadSalt.doFilter:60] - Creating CSRF prevention salt cache
[TRACE] 2021-11-10 00:19:04.363 [http-nio-8080-exec-164] [controller.LoadSalt.doFilter:69] - Generate the salt, store it in the users cache, and add it to the current request
[TRACE] 2021-11-10 00:19:04.363 [http-nio-8080-exec-164] [controller.ValidateSalt.doFilter:50] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[DEBUG] 2021-11-10 00:19:04.364 [http-nio-8080-exec-164] [controller.ValidateSalt.doFilter:58] - Validating that the salt is in the cache
[DEBUG] 2021-11-10 00:19:04.364 [http-nio-8080-exec-164] [controller.ValidateSalt.doFilter:66] - Salt is in cache, thus moving on
[TRACE] 2021-11-10 00:19:04.365 [http-nio-8080-exec-164] [controller.Install.processRequest:54] - Start processing request in eu.europa.ec.re3gistry2.web.controller.Install
[DEBUG] 2021-11-10 00:19:04.365 [http-nio-8080-exec-164] [utility.Configuration.initServlet:162] - Start initialising servlet
[DEBUG] 2021-11-10 00:19:04.365 [http-nio-8080-exec-164] [utility.Configuration.initServlet:180] - Proceed initialising servlet
[TRACE] 2021-11-10 00:19:04.365 [http-nio-8080-exec-164] [utility.Configuration.initServlet:183] - Initialise properties
[TRACE] 2021-11-10 00:19:04.366 [http-nio-8080-exec-164] [utility.Configuration.initServlet:188] - Initialise localisation
[TRACE] 2021-11-10 00:19:04.366 [http-nio-8080-exec-164] [utility.Configuration.initServlet:193] - Initialise available languages in session if needed
[DEBUG] 2021-11-10 00:19:04.366 [http-nio-8080-exec-164] [utility.Configuration.initServlet:205] - Current page name=/install
[TRACE] 2021-11-10 00:19:04.366 [http-nio-8080-exec-164] [utility.Configuration.initServlet:213] - No user found in the session, checking user
[TRACE] 2021-11-10 00:19:04.382 [http-nio-8080-exec-164] [utility.UserHelper.checkUser:81] - loginType=SHIRO
[DEBUG] 2021-11-10 00:19:04.383 [http-nio-8080-exec-164] [utility.Configuration.initServlet:221] - No user found
[TRACE] 2021-11-10 00:19:04.394 [http-nio-8080-exec-164] [controller.Install.processRequest:64] - Session id: 37FC2D1C38C865EC42B307E8FF4FE1C3
[DEBUG] 2021-11-10 00:19:04.395 [http-nio-8080-exec-164] [controller.Install.processRequest:74] - install step = clean-installation
[TRACE] 2021-11-10 00:19:47.279 [http-nio-8080-exec-176] [controller.LoadSalt.doFilter:52] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[TRACE] 2021-11-10 00:19:47.279 [http-nio-8080-exec-176] [controller.LoadSalt.doFilter:60] - Creating CSRF prevention salt cache
[TRACE] 2021-11-10 00:19:47.280 [http-nio-8080-exec-176] [controller.LoadSalt.doFilter:69] - Generate the salt, store it in the users cache, and add it to the current request
[TRACE] 2021-11-10 00:19:47.280 [http-nio-8080-exec-176] [controller.ValidateSalt.doFilter:50] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[DEBUG] 2021-11-10 00:19:47.280 [http-nio-8080-exec-176] [controller.ValidateSalt.doFilter:58] - Validating that the salt is in the cache
[DEBUG] 2021-11-10 00:19:47.280 [http-nio-8080-exec-176] [controller.ValidateSalt.doFilter:66] - Salt is in cache, thus moving on
[TRACE] 2021-11-10 00:19:47.281 [http-nio-8080-exec-176] [controller.Install.processRequest:54] - Start processing request in eu.europa.ec.re3gistry2.web.controller.Install
[DEBUG] 2021-11-10 00:19:47.281 [http-nio-8080-exec-176] [utility.Configuration.initServlet:162] - Start initialising servlet
[DEBUG] 2021-11-10 00:19:47.281 [http-nio-8080-exec-176] [utility.Configuration.initServlet:180] - Proceed initialising servlet
[TRACE] 2021-11-10 00:19:47.282 [http-nio-8080-exec-176] [utility.Configuration.initServlet:183] - Initialise properties
[TRACE] 2021-11-10 00:19:47.282 [http-nio-8080-exec-176] [utility.Configuration.initServlet:188] - Initialise localisation
[TRACE] 2021-11-10 00:19:47.282 [http-nio-8080-exec-176] [utility.Configuration.initServlet:193] - Initialise available languages in session if needed
[DEBUG] 2021-11-10 00:19:47.283 [http-nio-8080-exec-176] [utility.Configuration.initServlet:205] - Current page name=/install
[TRACE] 2021-11-10 00:19:47.283 [http-nio-8080-exec-176] [utility.Configuration.initServlet:213] - No user found in the session, checking user
[TRACE] 2021-11-10 00:19:47.308 [http-nio-8080-exec-176] [utility.UserHelper.checkUser:81] - loginType=SHIRO
[DEBUG] 2021-11-10 00:19:47.308 [http-nio-8080-exec-176] [utility.Configuration.initServlet:221] - No user found
[TRACE] 2021-11-10 00:19:47.320 [http-nio-8080-exec-176] [controller.Install.processRequest:64] - Session id: A6D887CB56C1EA19534555744763D60B
[DEBUG] 2021-11-10 00:19:47.320 [http-nio-8080-exec-176] [controller.Install.processRequest:74] - install step = clean-installation-summary
[TRACE] 2021-11-10 00:19:58.745 [http-nio-8080-exec-173] [controller.LoadSalt.doFilter:52] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[TRACE] 2021-11-10 00:19:58.746 [http-nio-8080-exec-173] [controller.LoadSalt.doFilter:60] - Creating CSRF prevention salt cache
[TRACE] 2021-11-10 00:19:58.746 [http-nio-8080-exec-173] [controller.LoadSalt.doFilter:69] - Generate the salt, store it in the users cache, and add it to the current request
[TRACE] 2021-11-10 00:19:58.747 [http-nio-8080-exec-173] [controller.ValidateSalt.doFilter:50] - Start filter eu.europa.ec.re3gistry2.web.controller.ValidateSalt
[DEBUG] 2021-11-10 00:19:58.747 [http-nio-8080-exec-173] [controller.ValidateSalt.doFilter:58] - Validating that the salt is in the cache
[DEBUG] 2021-11-10 00:19:58.747 [http-nio-8080-exec-173] [controller.ValidateSalt.doFilter:66] - Salt is in cache, thus moving on
[TRACE] 2021-11-10 00:19:58.748 [http-nio-8080-exec-173] [controller.Install.processRequest:54] - Start processing request in eu.europa.ec.re3gistry2.web.controller.Install
[DEBUG] 2021-11-10 00:19:58.748 [http-nio-8080-exec-173] [utility.Configuration.initServlet:162] - Start initialising servlet
[DEBUG] 2021-11-10 00:19:58.748 [http-nio-8080-exec-173] [utility.Configuration.initServlet:180] - Proceed initialising servlet
[TRACE] 2021-11-10 00:19:58.748 [http-nio-8080-exec-173] [utility.Configuration.initServlet:183] - Initialise properties
[TRACE] 2021-11-10 00:19:58.749 [http-nio-8080-exec-173] [utility.Configuration.initServlet:188] - Initialise localisation
[TRACE] 2021-11-10 00:19:58.749 [http-nio-8080-exec-173] [utility.Configuration.initServlet:193] - Initialise available languages in session if needed
[DEBUG] 2021-11-10 00:19:58.749 [http-nio-8080-exec-173] [utility.Configuration.initServlet:205] - Current page name=/install
[TRACE] 2021-11-10 00:19:58.749 [http-nio-8080-exec-173] [utility.Configuration.initServlet:213] - No user found in the session, checking user
[TRACE] 2021-11-10 00:19:58.770 [http-nio-8080-exec-173] [utility.UserHelper.checkUser:81] - loginType=SHIRO
[DEBUG] 2021-11-10 00:19:58.770 [http-nio-8080-exec-173] [utility.Configuration.initServlet:221] - No user found
[TRACE] 2021-11-10 00:19:58.782 [http-nio-8080-exec-173] [controller.Install.processRequest:64] - Session id: 0A70FB5F1D490AE8CCE36E1BB4A60FA6
[DEBUG] 2021-11-10 00:19:58.782 [http-nio-8080-exec-173] [controller.Install.processRequest:74] - install step = clean-installation-process
[INFO ] 2021-11-10 00:19:58.782 [http-nio-8080-exec-173] [controller.Install.processRequest:110] - Start clean installation
[ERROR] 2021-11-10 00:19:58.783 [http-nio-8080-exec-173] [controller.Install.processRequest:123] - Exception occurred in step clean-installation-process
java.lang.Exception: There is no user
    at eu.europa.ec.re3gistry2.javaapi.handler.RegInstallationStepCleanInstallationProcessHandler.createRegistryFromSession(RegInstallationStepCleanInstallationProcessHandler.java:78) ~[Re3gistry2JavaAPI-1.0.jar:?]
    at eu.europa.ec.re3gistry2.javaapi.handler.RegInstallationStepCleanInstallationProcessHandler.<init>(RegInstallationStepCleanInstallationProcessHandler.java:65) ~[Re3gistry2JavaAPI-1.0.jar:?]
    at eu.europa.ec.re3gistry2.web.controller.Install.processRequest(Install.java:113) [classes/:?]
    at eu.europa.ec.re3gistry2.web.controller.Install.doPost(Install.java:180) [classes/:?]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:681) [servlet-api.jar:?]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) [servlet-api.jar:?]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) [catalina.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.70]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat-websocket.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.70]
    at eu.europa.ec.re3gistry2.web.controller.CharacterEncodingFilter.doFilter(CharacterEncodingFilter.java:47) [classes/:?]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.70]
    at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90) [shiro-core-1.8.0.jar:1.8.0]
    at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83) [shiro-core-1.8.0.jar:1.8.0]
    at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387) [shiro-core-1.8.0.jar:1.8.0]
    at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [shiro-web-1.2.4.jar:1.2.4]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.70]
    at eu.europa.ec.re3gistry2.web.controller.ValidateSalt.doFilter(ValidateSalt.java:67) [classes/:?]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.70]
    at eu.europa.ec.re3gistry2.web.controller.LoadSalt.doFilter(LoadSalt.java:78) [classes/:?]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.70]
    at org.apache.logging.log4j.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:71) [log4j-web-2.14.1.jar:2.14.1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.70]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.70]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:196) [catalina.jar:8.5.70]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) [catalina.jar:8.5.70]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:544) [catalina.jar:8.5.70]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135) [catalina.jar:8.5.70]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [catalina.jar:8.5.70]
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:698) [catalina.jar:8.5.70]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) [catalina.jar:8.5.70]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:364) [catalina.jar:8.5.70]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:624) [tomcat-coyote.jar:8.5.70]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-coyote.jar:8.5.70]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:831) [tomcat-coyote.jar:8.5.70]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1650) [tomcat-coyote.jar:8.5.70]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.70]
    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) [tomcat-util.jar:8.5.70]
    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) [tomcat-util.jar:8.5.70]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.70]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_292]

emanuelaepure10 commented 2 years ago

Dear @heidivanparys ,

Could you please check if at this moment the user exist in the database? My first impresion is that something wrong happened in the commit of the user in the databse, so the user was null so the session was not set. https://github.com/ec-jrc/re3gistry/blob/79f806053066cfa1fb1636ce34b64912004ccb32/sources/Re3gistry2JavaAPI/src/main/java/eu/europa/ec/re3gistry2/javaapi/handler/RegInstallationStep3Handler.java#L59

Thank you

heidivanparys commented 2 years ago

Dear @emanuelaepure10 , the administrator exists in the database at the tine of the error. I tried the installation several times, and every time I deleted the user and its role mapping from the database manually before trying again.

I added extra logging to follow the process, it says:

[DEBUG] 2021-11-10 00:19:01.482 [http-nio-8080-exec-170] [handler.RegInstallationHandler.createRegUser:602] - Creating new administrator user
[DEBUG] 2021-11-10 00:19:01.487 [http-nio-8080-exec-170] [handler.RegInstallationHandler.createRegUser:622] - Administrator user eu.europa.ec.re3gistry2.model.RegUser[ uuid=4ea865adface3494971c6deb5ab1deac ] created
[DEBUG] 2021-11-10 00:19:01.608 [http-nio-8080-exec-170] [handler.RegInstallationHandler.createRegUser:631] - Administrator user eu.europa.ec.re3gistry2.model.RegUser[ uuid=4ea865adface3494971c6deb5ab1deac ] persisted and committed

Note that I also added log lines writing the HTTP session number, which is different all the time, which seems a bit odd, as the user seems to be stored in the session. If a new session is created for every step (the question is why?), that would explain why no user can be found in the (new) session, as it was set on an older session.

[TRACE] 2021-11-10 00:18:42.341 [http-nio-8080-exec-173] [controller.Install.processRequest:64] - Session id: 88884FC5F0ECD8961C899BB7B3C47123
[DEBUG] 2021-11-10 00:18:42.342 [http-nio-8080-exec-173] [controller.Install.processRequest:74] - install step = 1
[...]
[TRACE] 2021-11-10 00:18:48.146 [http-nio-8080-exec-174] [controller.Install.processRequest:64] - Session id: 4C933354ED0B8B9D1022ECFA9360356C
[DEBUG] 2021-11-10 00:18:48.222 [http-nio-8080-exec-174] [controller.Install.processRequest:74] - install step = 2
[...]
[TRACE] 2021-11-10 00:19:01.467 [http-nio-8080-exec-170] [controller.Install.processRequest:64] - Session id: A2A11E01D46DBD7F3450BD9599F1AC39
[DEBUG] 2021-11-10 00:19:01.467 [http-nio-8080-exec-170] [controller.Install.processRequest:74] - install step = 3
[...]
[TRACE] 2021-11-10 00:19:04.394 [http-nio-8080-exec-164] [controller.Install.processRequest:64] - Session id: 37FC2D1C38C865EC42B307E8FF4FE1C3
[DEBUG] 2021-11-10 00:19:04.395 [http-nio-8080-exec-164] [controller.Install.processRequest:74] - install step = clean-installation
[...]
[TRACE] 2021-11-10 00:19:47.320 [http-nio-8080-exec-176] [controller.Install.processRequest:64] - Session id: A6D887CB56C1EA19534555744763D60B
[DEBUG] 2021-11-10 00:19:47.320 [http-nio-8080-exec-176] [controller.Install.processRequest:74] - install step = clean-installation-summary
[...]
[TRACE] 2021-11-10 00:19:58.782 [http-nio-8080-exec-173] [controller.Install.processRequest:64] - Session id: 0A70FB5F1D490AE8CCE36E1BB4A60FA6
[DEBUG] 2021-11-10 00:19:58.782 [http-nio-8080-exec-173] [controller.Install.processRequest:74] - install step = clean-installation-process
[...]

alexanderkotsev commented 2 years ago

Dear @heidivanparys - something that might be useful for deploying the tool is the build shell script we created for OSGEO Live. Following the steps in the script works on Lubuntu 18.

heidivanparys commented 2 years ago

Dear @heidivanparys - something that might be useful for deploying the tool is the build shell script we created for OSGEO Live. Following the steps in the script works on Lubuntu 18.

Dear @alexanderkotsev, thanks for the tip, but I'm afraid it won't help, as that script depends on PostgreSQL, and we want to use Oracle, in order to comply with our agency’s architectural principles [1]. The error we get now really seems to be completely unrelated to the database.

[1] This should be possible according to the documentation of both Re3gistry and EclipseLink. Changes needed for that were:

adding the Oracle driver as a dependency (https://github.com/heidivanparys/re3gistry/commit/c913f257b7ecce30702b18683970feda60e60377)
introducing an additional property persistence.jdbc.datasource (https://github.com/heidivanparys/re3gistry/commit/390e8831dce4e10ae60fe447860624e054118330)
building the software ourselves using Maven with a specific Maven profile setting persistence.jdbc.driver, persistence.jdbc.url and persistence.jdbc.datasource to the relevant values for our Oracle database.
modifying the database script, so it is fit for Oracle (https://github.com/heidivanparys/re3gistry/commit/ba097f835e395026c990ab9f32cfa0b29e4ad3cd)

This part works fine so far. We've had one error because EclipseLink expected another data type, see below, but as we got the Oracle error in the log file, we could easily fix that, recreate the database schema and try again.

org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLSyntaxErrorException: ORA-01722: invalid number

Error Code: 1722
Call: SELECT uuid, active, editdate, insertdate, iso6391code, iso6392code, label, masterlanguage FROM reg_languagecode WHERE (active = ?)
            bind => [true]

emanuelaepure10 commented 2 years ago

As I can see here https://github.com/ec-jrc/re3gistry/blob/79f806053066cfa1fb1636ce34b64912004ccb32/sources/Re3gistry2/src/main/java/eu/europa/ec/re3gistry2/web/controller/Install.java the session is passed as a parameter to all the steps.

But, it might be usuful to use this solution https://stackoverflow.com/questions/2138245/session-is-lost-and-created-as-new-in-every-servlet-request or better this https://experienceleaguecommunities.adobe.com/t5/adobe-experience-manager/new-httpsession-on-every-request/m-p/214835 which sets the <%@page session="false"%> in all the pages of the install package https://github.com/ec-jrc/re3gistry/tree/79f806053066cfa1fb1636ce34b64912004ccb32/sources/Re3gistry2/src/main/webapp/jsp/install Please see as well: https://stackoverflow.com/questions/5515729/why-set-a-jsp-page-session-false-directive

I havent yet test this solution but might help you to get the user from the same session. Please let us know if this helps

heidivanparys commented 2 years ago

Thanks for the investigation and the links, some answers in there helped me to pinpoint the actual problem.

Now, I managed to get to the page saying that the Re3gistry software has been properly installed. The log also shows the same session id all the time now.

The log still contains errors, but those apparently didn't affect the installation process. See #80.

emanuelaepure10 commented 2 years ago

@heidivanparys I will consider this closed and we will work on the #80 . Thank you for you effort

ec-jrc / re3gistry

Installation (from scratch, no migration) gives "no user found" #78