keycloakify icon indicating copy to clipboard operation
keycloakify copied to clipboard
verified publisher icon keycloakify

Account Applications page error: An error has occurred when reading existing sub-variable "rolesStream"

Open adhurjaty opened this issue 11 months ago • 4 comments

Summary

When trying to load the Applications account page, I get a network timeout. This is with the "Multi-Page" account theme implementation. Digging into the logs, I see the following error:

Error executing FreeMarker template part in the #attempt block: freemarker.core._TemplateModelException: An error has occurred when reading existing sub-variable "rolesStream"; see cause exception! The type of the containing value was: extended_hash+string (org.keycloak.models.delegate.ClientModelLazyDelegate$WithId wrapped into f.e.b.StringModel)
Stack trace

at freemarker.ext.beans.BeanModel.get(BeanModel.java:185) at freemarker.core.DynamicKeyName.dealWithStringKey(DynamicKeyName.java:166) at freemarker.core.DynamicKeyName._eval(DynamicKeyName.java:86) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.ExistsExpression._eval(ExistsExpression.java:49) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.Expression.evalToBoolean(Expression.java:177) at freemarker.core.Expression.evalToBoolean(Expression.java:163) at freemarker.core.NotExpression.evalToBoolean(NotExpression.java:34) at freemarker.core.ConditionalBlock.accept(ConditionalBlock.java:48) at freemarker.core.Environment.visit(Environment.java:335) at freemarker.core.Environment.visit(Environment.java:341) at freemarker.core.Environment.visitAttemptRecover(Environment.java:552) at freemarker.core.AttemptBlock.accept(AttemptBlock.java:45) at freemarker.core.Environment.visit(Environment.java:371) at freemarker.core.IteratorBlock$IterationContext.executedNestedContentForCollOrSeqListing(IteratorBlock.java:291) at freemarker.core.IteratorBlock$IterationContext.executeNestedContent(IteratorBlock.java:271) at freemarker.core.IteratorBlock$IterationContext.accept(IteratorBlock.java:244) at freemarker.core.Environment.visitIteratorBlock(Environment.java:645) at freemarker.core.IteratorBlock.acceptWithResult(IteratorBlock.java:108) at freemarker.core.IteratorBlock.accept(IteratorBlock.java:94) at freemarker.core.Environment.visit(Environment.java:335) at freemarker.core.Environment.visit(Environment.java:377) at freemarker.core.Environment.invokeMacroOrFunctionCommonPart(Environment.java:877) at freemarker.core.Environment.invokeMacro(Environment.java:813) at freemarker.core.Environment.invokeFunction(Environment.java:829) at freemarker.core.MethodCall._eval(MethodCall.java:65) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.Assignment.accept(Assignment.java:134) at freemarker.core.Environment.visit(Environment.java:371) at freemarker.core.IteratorBlock$IterationContext.executedNestedContentForCollOrSeqListing(IteratorBlock.java:291) at freemarker.core.IteratorBlock$IterationContext.executeNestedContent(IteratorBlock.java:271) at freemarker.core.IteratorBlock$IterationContext.accept(IteratorBlock.java:244) at freemarker.core.Environment.visitIteratorBlock(Environment.java:645) at freemarker.core.IteratorBlock.acceptWithResult(IteratorBlock.java:108) at freemarker.core.IteratorBlock.accept(IteratorBlock.java:94) at freemarker.core.Environment.visit(Environment.java:335) at freemarker.core.Environment.visit(Environment.java:377) at freemarker.core.Environment.invokeMacroOrFunctionCommonPart(Environment.java:877) at freemarker.core.Environment.invokeMacro(Environment.java:813) at freemarker.core.Environment.invokeFunction(Environment.java:829) at freemarker.core.MethodCall._eval(MethodCall.java:65) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.Assignment.accept(Assignment.java:134) at freemarker.core.Environment.visit(Environment.java:371) at freemarker.core.IteratorBlock$IterationContext.executedNestedContentForCollOrSeqListing(IteratorBlock.java:321) at freemarker.core.IteratorBlock$IterationContext.executeNestedContent(IteratorBlock.java:271) at freemarker.core.IteratorBlock$IterationContext.accept(IteratorBlock.java:244) at freemarker.core.Environment.visitIteratorBlock(Environment.java:645) at freemarker.core.IteratorBlock.acceptWithResult(IteratorBlock.java:108) at freemarker.core.IteratorBlock.accept(IteratorBlock.java:94) at freemarker.core.Environment.visit(Environment.java:335) at freemarker.core.Environment.visit(Environment.java:377) at freemarker.core.Environment.invokeMacroOrFunctionCommonPart(Environment.java:877) at freemarker.core.Environment.invokeMacro(Environment.java:813) at freemarker.core.Environment.invokeFunction(Environment.java:829) at freemarker.core.MethodCall._eval(MethodCall.java:65) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.Assignment.accept(Assignment.java:134) at freemarker.core.Environment.visit(Environment.java:371) at freemarker.core.IteratorBlock$IterationContext.executedNestedContentForCollOrSeqListing(IteratorBlock.java:291) at freemarker.core.IteratorBlock$IterationContext.executeNestedContent(IteratorBlock.java:271) at freemarker.core.IteratorBlock$IterationContext.accept(IteratorBlock.java:244) at freemarker.core.Environment.visitIteratorBlock(Environment.java:645) at freemarker.core.IteratorBlock.acceptWithResult(IteratorBlock.java:108) at freemarker.core.IteratorBlock.accept(IteratorBlock.java:94) at freemarker.core.Environment.visit(Environment.java:335) at freemarker.core.Environment.visit(Environment.java:377) at freemarker.core.Environment.invokeMacroOrFunctionCommonPart(Environment.java:877) at freemarker.core.Environment.invokeMacro(Environment.java:813) at freemarker.core.Environment.invokeFunction(Environment.java:829) at freemarker.core.MethodCall._eval(MethodCall.java:65) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.Assignment.accept(Assignment.java:134) at freemarker.core.Environment.visit(Environment.java:371) at freemarker.core.IteratorBlock$IterationContext.executedNestedContentForCollOrSeqListing(IteratorBlock.java:291) at freemarker.core.IteratorBlock$IterationContext.executeNestedContent(IteratorBlock.java:271) at freemarker.core.IteratorBlock$IterationContext.accept(IteratorBlock.java:244) at freemarker.core.Environment.visitIteratorBlock(Environment.java:645) at freemarker.core.IteratorBlock.acceptWithResult(IteratorBlock.java:108) at freemarker.core.IteratorBlock.accept(IteratorBlock.java:94) at freemarker.core.Environment.visit(Environment.java:335) at freemarker.core.Environment.visit(Environment.java:377) at freemarker.core.Environment.invokeMacroOrFunctionCommonPart(Environment.java:877) at freemarker.core.Environment.invokeMacro(Environment.java:813) at freemarker.core.Environment.invokeFunction(Environment.java:829) at freemarker.core.MethodCall._eval(MethodCall.java:65) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.BuiltInsForOutputFormatRelated$AbstractConverterBI.calculateResult(BuiltInsForOutputFormatRelated.java:50) at freemarker.core.MarkupOutputFormatBoundBuiltIn._eval(MarkupOutputFormatBoundBuiltIn.java:40) at freemarker.core.Expression.eval(Expression.java:101) at freemarker.core.DollarVariable.calculateInterpolatedStringOrMarkup(DollarVariable.java:104) at freemarker.core.DollarVariable.accept(DollarVariable.java:63) at freemarker.core.Environment.visit(Environment.java:335) at freemarker.core.Environment.visit(Environment.java:341) at freemarker.core.Environment.process(Environment.java:314) at freemarker.template.Template.process(Template.java:383) at org.keycloak.theme.freemarker.DefaultFreeMarkerProvider.processTemplate(DefaultFreeMarkerProvider.java:49) at org.keycloak.forms.account.freemarker.FreeMarkerAccountProvider.processTemplate(FreeMarkerAccountProvider.java:290) at org.keycloak.forms.account.freemarker.FreeMarkerAccountProvider.createResponse(FreeMarkerAccountProvider.java:208) at org.keycloak.services.resources.account.AccountFormService.forwardToPage(AccountFormService.java:311) at org.keycloak.services.resources.account.AccountFormService.applicationsPage(AccountFormService.java:419) at org.keycloak.services.resources.account.AccountFormService$quarkusrestinvoker$applicationsPage_52f8c7b85bca447b8ad509e81b4036c4744fcafe.invoke(Unknown Source) at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29) at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141) at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582) at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513) at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538) at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29) at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:1583) Caused by: java.lang.reflect.InvocationTargetException at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:118) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at freemarker.ext.beans.BeansWrapper.invokeMethod(BeansWrapper.java:1553) at freemarker.ext.beans.BeanModel.invokeThroughDescriptor(BeanModel.java:233) at freemarker.ext.beans.BeanModel.get(BeanModel.java:152) ... 114 more Caused by: org.keycloak.models.ModelException: Database operation failed at org.keycloak.connections.jpa.PersistenceExceptionConverter.convert(PersistenceExceptionConverter.java:109) at org.keycloak.connections.jpa.PersistenceExceptionConverter.invoke(PersistenceExceptionConverter.java:68) at jdk.proxy3/jdk.proxy3.$Proxy91.createNamedQuery(Unknown Source) at org.keycloak.models.jpa.JpaRealmProvider.getClientRolesStream(JpaRealmProvider.java:386) at org.keycloak.models.RoleProvider.getClientRolesStream(RoleProvider.java:124) at org.keycloak.storage.RoleStorageManager.getClientRolesStream(RoleStorageManager.java:221) at org.keycloak.models.cache.infinispan.RealmCacheSession.getClientRolesStream(RealmCacheSession.java:704) at org.keycloak.models.cache.infinispan.ClientAdapter.getRolesStream(ClientAdapter.java:560) at org.keycloak.models.delegate.ClientModelLazyDelegate.getRolesStream(ClientModelLazyDelegate.java:579) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ... 118 more Caused by: org.hibernate.HibernateException: Transaction was rolled back in a different thread at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorTrackingImpl.processAnyDelayedAfterCompletion(SynchronizationCallbackCoordinatorTrackingImpl.java:90) at org.hibernate.internal.SessionImpl.delayedAfterCompletion(SessionImpl.java:608) at org.hibernate.internal.AbstractSharedSessionContract.buildNamedQuery(AbstractSharedSessionContract.java:1068) at org.hibernate.internal.AbstractSharedSessionContract.buildNamedQuery(AbstractSharedSessionContract.java:1089) at org.hibernate.internal.AbstractSharedSessionContract.createNamedQuery(AbstractSharedSessionContract.java:980) at org.hibernate.internal.SessionImpl.createNamedQuery(SessionImpl.java:202) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at org.keycloak.connections.jpa.PersistenceExceptionConverter.invoke(PersistenceExceptionConverter.java:66) ... 126 more

This only happens in certain environments, not localhost, so reproducing this bug may be difficult

Keycloakify version

10.1.4 (though I also tried with 11.8)

Keycloak version

25.0.6

adhurjaty avatar May 12 '25 16:05 adhurjaty

Thank you for reporting. I'm a bit under water. This might take time until I find the time to solve this.

If you want this to be put on top of the stack you can make a donnation.

garronej avatar May 20 '25 15:05 garronej

Did a bit more digging. Seeing this log line hundreds of times and a StackOverFlowException before the above exception:

freemarker.core.AddConcatExpression$ConcatenatedHash.get(AddConcatExpression.java:233)

adhurjaty avatar May 28 '25 20:05 adhurjaty

Looked into this some more. Seems that the issue is that the ApplicationsBean will fetch all clients that are not bearerOnly. My assumption was this page would just show clients that the user had consented to, but it shows every client the user could authenticate with (which is all of them).

Our realm has 1000+ clients, so running the recursive isSubPath freemarker function is overflowing the callstack (I think).

I'm not sure there's anything that can be done on the Keycloakify side other than bail out of the function and set applications to [] if the client list is too large. This is probably pointing to us using the Single-Page configuration going forward, though we do really like the storybook integration with the Multi-Page config.

adhurjaty avatar May 28 '25 22:05 adhurjaty

Hey @adhurjaty,

Thanks for looking into it! There’s definitely things we can do about it, it can be fixed but yeah, the Multi-Page theme could really use some love. We’re not planning to deprecate it, since it’s currently the only way for Angular and Svelte users to create an Account theme. That said, it’s a bit behind right now, with known bugs I haven’t had time to tackle.

If you're okay with using React, the Single-Page theme is more up-to-date and better maintained.

As for Storybook, you shouldn’t miss it too much, hot reloading makes testing quite smooth.

You might also find this recent talk helpful: https://youtu.be/S-B8Db2dStk?si=ALYJmKvmnNmOXUGA&t=1084

garronej avatar Jun 01 '25 00:06 garronej