search

JanssenProject / jans

An open source enterprise digital identity platform for CIAM or workforce... Janssen is a distribution of standards-based, developer friendly, components that are engineered to work together in any cloud. #OAuth #OpenID #FIDO
https://docs.jans.io
Apache License 2.0
472 stars 75 forks source link

fix: white Screen after device flow authn in ubuntu 22 install #4237

Closed nynymike closed 1 year ago

nynymike commented 1 year ago

After fresh install of Jans 1.0.0-10, I get a whitescreen when I login using device flow.

In jans-auth_script.log: 

2023-03-19 21:05:26,866 INFO  [qtp1549725679-21] 29a8bcc3-85e7-4a2f-a1f0-390d59e2528b [io.jans.service.PythonService$PythonLoggerOutputStream] (PythonService.java:244) - Agama. Request param 'agama_flow' is missing or has no value

In jans-auth.log:

2023-03-19 21:04:56,923 INFO  [qtp1549725679-21] 27364e68-039e-440a-8c4a-1671007c2345 [as.server.authorize.ws.rs.DeviceAuthorizationRestWebServiceImpl] (DeviceAuthorizationRestWebServiceImpl.java:137) - Device authorization flow initiated, userCode: SCJC-HPCK, deviceCode: 7753d46a16b6a6d1e3a53212a514fb3f42a2c4120ebf1324, clientId: 2000.2e140f93-9da7-4c29-8ed3-292841598009, verificationUri: https://modena.gluu.me/device-code, expiresIn: 1800, interval: 5
2023-03-19 21:05:12,771 INFO  [qtp1549725679-21] c4d85e0f-586a-4faf-91f8-4fcff2d67aeb [as.server.authorize.ws.rs.DeviceAuthorizationAction] (DeviceAuthorizationAction.java:97) - Processing device authorization page request, userCode: null, code: null, sessionId: null, state: null, sessionState: null, error: null, errorDescription: null
2023-03-19 21:05:12,774 ERROR [qtp1549725679-21] c4d85e0f-586a-4faf-91f8-4fcff2d67aeb [io.jans.as.server.service.SessionIdService] (SessionIdService.java:787) - Failed to get session by dn: jansId=f9c0068f-e394-45f2-8201-59c97165a926,ou=sessions,o=jans. Failed to find entry: 'jansId=f9c0068f-e394-45f2-8201-59c97165a926,ou=sessions,o=jans'
2023-03-19 21:05:18,187 INFO  [ForkJoinPool.commonPool-worker-1]  [io.jans.ads.Deployer] (Deployer.java:400) - Syncing in-memory state with DB state
2023-03-19 21:05:18,188 INFO  [ForkJoinPool.commonPool-worker-1]  [io.jans.ads.Deployer] (Deployer.java:406) - 0 successful deployments found
2023-03-19 21:05:26,708 INFO  [qtp1549725679-21] e7b9d484-194b-47e3-a71d-4f17093be3ad [as.server.authorize.ws.rs.DeviceAuthorizationAction] (DeviceAuthorizationAction.java:231) - Redirecting to authorization code flow to process device authorization, data: DeviceAuthorizationCacheControl{userCode='SCJC-HPCK', deviceCode='7753d46a16b6a6d1e3a53212a514fb3f42a2c4120ebf1324', client=DeletableEntity{expirationDate=null, deletable=false} BaseEntry [dn=inum=2000.2e140f93-9da7-4c29-8ed3-292841598009,ou=clients,o=jans], scopes=[openid, profile, offline_access, email], verificationUri='https://modena.gluu.me/device-code', expiresIn=1800, interval=5, lastAccessControl=1679259896850, status=PENDING}
2023-03-19 21:05:26,749 ERROR [qtp1549725679-17] b9080e00-cb58-4505-a767-1c8f55c0600c [org.jboss.resteasy.core.ExceptionHandler] (ExceptionHandler.java:292) - RESTEASY002010: Failed to execute
jakarta.ws.rs.WebApplicationException: HTTP 302 Found
    at io.jans.as.server.authorize.ws.rs.AuthorizeRestWebServiceImpl.ifUserIsNull(AuthorizeRestWebServiceImpl.java:731) ~[classes/:?]
    at io.jans.as.server.authorize.ws.rs.AuthorizeRestWebServiceImpl.authorize(AuthorizeRestWebServiceImpl.java:346) ~[classes/:?]
    at io.jans.as.server.authorize.ws.rs.AuthorizeRestWebServiceImpl.requestAuthorization(AuthorizeRestWebServiceImpl.java:262) ~[classes/:?]
    at io.jans.as.server.authorize.ws.rs.AuthorizeRestWebServiceImpl.requestAuthorizationGet(AuthorizeRestWebServiceImpl.java:203) ~[classes/:?]
    at io.jans.as.server.authorize.ws.rs.AuthorizeRestWebServiceImpl$Proxy$_$$_WeldClientProxy.requestAuthorizationGet(Unknown Source) ~[classes/:?]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:408) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:69) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:249) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:60) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:55) ~[resteasy-core-6.0.3.Final.jar:6.0.3.Final]
    at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587) ~[jetty-jakarta-servlet-api-5.0.2.jar:?]
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764) ~[?:?]
    at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665) ~[?:?]
    at io.jans.as.server.audit.debug.ServletLoggingFilter.doFilter(ServletLoggingFilter.java:71) ~[classes/:?]
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:210) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at io.jans.as.server.auth.AuthenticationFilter.doFilter(AuthenticationFilter.java:252) ~[classes/:?]
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at io.jans.server.filters.AbstractCorsFilter.handleNonCORS(AbstractCorsFilter.java:344) ~[jans-core-server-1.0.10.jar:?]
    at io.jans.server.filters.AbstractCorsFilter.doFilter(AbstractCorsFilter.java:121) ~[jans-core-server-1.0.10.jar:?]
    at io.jans.as.server.filter.CorsFilter.doFilter(CorsFilter.java:116) ~[classes/:?]
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at io.jans.as.server.filter.CorrelationIdFilter.doFilter(CorrelationIdFilter.java:49) ~[classes/:?]
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.websocket.servlet.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:170) ~[websocket-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:202) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1635) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131) ~[?:?]
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578) ~[jetty-security-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) ~[?:?]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223) ~[?:?]
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1571) ~[jetty-server-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221) ~[?:?]
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1375) ~[jetty-server-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176) ~[?:?]
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484) ~[jetty-servlet-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1544) ~[jetty-server-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174) ~[?:?]
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1297) ~[jetty-server-11.0.11.jar:11.0.11]
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129) ~[?:?]
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:192) ~[?:?]
    at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:51) ~[?:?]
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122) ~[?:?]
    at org.eclipse.jetty.server.Server.handle(Server.java:562) ~[?:?]
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505) ~[?:?]
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762) ~[?:?]
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497) ~[?:?]
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282) ~[?:?]
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:319) ~[?:?]
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100) ~[?:?]
    at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:412) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:381) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:268) ~[?:?]
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.lambda$new$0(AdaptiveExecutionStrategy.java:138) ~[?:?]
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:407) ~[?:?]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:894) ~[?:?]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1038) ~[?:?]
    at java.lang.Thread.run(Thread.java:829) ~[?:?]

Apache Log for a different request:

modena.gluu.me:443 192.168.122.1 - - [19/Mar/2023:21:50:33 +0000] "GET /jans-auth/restv1/authorize?scope=openid+profile+offline_access+email&response_type=code&state=98eee8db-c967-4432-bbbb-03f93138a5ca&nonce=b68820ec-9891-46f8-9244-ea50c40ac0d6&client_id=2000.c8a4bf8c-b329-4d29-b8d9-cd9638b5d6cf HTTP/1.1" 302 662 "https://modena.gluu.me/device-code" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36"
modena.gluu.me:443 192.168.122.1 - - [19/Mar/2023:21:50:33 +0000] "GET /jans-auth/authorize.htm?scope=openid+profile+offline_access+email&response_type=code&redirect_uri=https%3A%2F%2Fmodena.gluu.me%2Fjans-auth%2Fdevice_authorization.htm&state=98eee8db-c967-4432-bbbb-03f93138a5ca&nonce=b68820ec-9891-46f8-9244-ea50c40ac0d6&client_id=2000.c8a4bf8c-b329-4d29-b8d9-cd9638b5d6cf HTTP/1.1" 200 1308 "https://modena.gluu.me/device-code" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36"
nynymike commented 1 year ago

Not sure what is the default acr, because I can't use the CLI...

manojs1978 commented 1 year ago

this issue is with all distributions

yuriyz commented 1 year ago

I've investigated this blank page issue. In short it redirects to /agama which returns blank content. Before when we installed AS, agama was not enabled. It sounds like we enabled it by default recently. To see it TRACE logs has to be enabled.

2023-03-17 16:34:28,312 TRACE [qtp952562199-20] bf4bdffd-e607-4dde-ba03-c21d906f5b9b [as.server.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:308) - Redirect to person authentication login page: /agama.xhtml

Recent changes are:

Here is how AS behaves currently:

  1. send authz request without acr_values
  2. AS see no acr_values and takes default server acr which is "simple_password_auth" (specified in jansAuthMode).
  3. AS trying to find PersonAuthentication script with name "simple_password_auth" but fail because there no such script enabled.
  4. Since AS can't redirect to script it looks up for default PersonAuthentication which is any script with highest level (AS useHighestLevelScriptIfAcrScriptNotFound=true property).
  5. During installation all "PersonAuthentication" scripts are disabled except agama.
  6. Hence AS takes agama script (because it's the only enabled right now) and redirects to "/agama.xhtml"

Result: blank page because "/agama.xhtml" is blank.

How do we want to proceed with it? Possible solutions: a) disable "agama" custom script -> AS will fall back to "/login.xhtml" and will allow user to login. It was AS behavior before agama enabled by default. b) enable "basic" and set jansAuthMode: basic. AS will find script and will redirect to it. c) provide fallback for "/agama.xhtml" so it renders default username/password page if there no flows. d) your proposal here ?

Question is how do we want it to work all together. We have to establish clear path so we avoid confusion in future.

yuriyz commented 1 year ago

We agreed to set "useHighestLevelScriptIfAcrScriptNotFound" to "false", so AS does not look up script itself.

smansoft commented 1 year ago

@yuriyz I could get working flow (obtaining of tokens), using /opt/jans/jans-cli/config-cli.py after disabling of these changes: https://github.com/JanssenProject/jans/commit/7e432dcde57657d1cfa1cd45bde2206156dc6905 As temp solution.

yuriyz commented 1 year ago

@smansoft right, with disabled agama it works. Question is how to get it working with agama.