CAS 6.2 up to v5/6.3 master, ticketgrantingticket table, JPA, logout Error 500 and TGT cleanup

144 views
Skip to first unread message

randomuser878

unread,
Nov 18, 2020, 5:30:52 PM11/18/20
to CAS Developer

Greetings

  Tried to look on the source code to no avail. If anyone can point to me the most likely place to solve the issue, I am willing to dabble on java.
Already asked on cas main list but no-community reply. Can not say for sure this is a bug.

Vanilla install JPA/MySQL 6.2.x and 6.3.x. Use the ticketgrantingticket and not encodedticket  table. It works when using encodedticket but why is it failint for ticketgrantingticket and unencrypted TGT.  All above works on 6.1.7.2.

To recreate: 
cas.ticket.registry.jpa.crypto.enabled=false
# to use ticketgrantingticket table did comment out the below entries.
# also left  empty without key values present.
cas.ticket.registry.jpa.crypto.signing.key=
cas.ticket.registry.jpa.crypto.signing.key-size=512
cas.ticket.registry.jpa.crypto.encryption.key=
cas.ticket.registry.jpa.crypto.encryption.key-size=16
cas.ticket.registry.jpa.crypto.alg=AES

To simulate on one ldap login.
https://yoursite.com/cas/login - OK
https://yoursite.com/cas/logout - Exception, Error 500,  fails to remove TGT
Scheduler job fails as well for every run.

Thanks for any hint you can provide me to proceed forward.


Exceptions snippets per logout and ticket cleanup.

=== Logout error /cas/logout ====
^[[36m2020-11-05 14:25:28,695 DEBUG [org.apereo.cas.web.FlowExecutionExceptionResolver] - <Ignoring the received exception [org.springframework.webflow.execution.ActionExecutionException: Exception thrown executing org.apereo.cas.web.flow.logout.TerminateSessionAction@31445f5 in state 'terminateSession' of flow 'logout' -- action execution attributes were 'map[[empty]]'] due to a type mismatch with handler [[FlowHandlerMapping.DefaultFlowHandler@3b69f7ce]]>^[[m
^[[36m2020-11-05 14:25:28,699 DEBUG [org.apereo.cas.web.FlowExecutionExceptionResolver] - <Ignoring the received exception [org.springframework.webflow.execution.ActionExecutionException: Exception thrown executing org.apereo.cas.web.flow.logout.TerminateSessionAction@31445f5 in state 'terminateSession' of flow 'logout' -- action execution attributes were 'map[[empty]]'] due to a type mismatch with handler [[FlowHandlerMapping.DefaultFlowHandler@3b69f7ce]]>^[[m
^[[1;31m2020-11-05 14:25:28,700 ERROR [org.springframework.boot.web.servlet.support.ErrorPageFilter] - <Forwarding to error page from request [/logout] due to exception [Exception thrown executing org.apereo.cas.web.flow.logout.TerminateSessionAction@31445f5 in state 'terminateSession' of flow 'logout' -- action execution attributes were 'map[[empty]]']>^[[m
org.springframework.webflow.execution.ActionExecutionException: Exception thrown executing org.apereo.cas.web.flow.logout.TerminateSessionAction@31445f5 in state 'terminateSession' of flow 'logout' -- action execution attributes were 'map[[empty]]'
        at org.springframework.webflow.execution.ActionExecutor.execute(ActionExecutor.java:62) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.action.EvaluateAction.doExecute(EvaluateAction.java:77) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.action.AbstractAction.execute(AbstractAction.java:188) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.execution.ActionExecutor.execute(ActionExecutor.java:51) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.engine.ActionState.doEnter(ActionState.java:101) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.engine.State.enter(State.java:194) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.engine.Flow.start(Flow.java:527) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:368) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:223) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.webflow.executor.FlowExecutorImpl.launchExecution(FlowExecutorImpl.java:139) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]

        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.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) ~[spring-core-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) ~[spring-cloud-context-2.2.2.RELEASE.jar:2.2.2.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at com.sun.proxy.$Proxy309.launchExecution(Unknown Source) ~[?:?]
        at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:264) ~[spring-webflow-2.5.1.RELEASE.jar:2.5.1.RELEASE]
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:626) ~[servlet-api.jar:4.0.FR]
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) ~[servlet-api.jar:4.0.FR]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[catalina.jar:9.0.39]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[catalina.jar:9.0.39]
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-websocket.jar:9.0.39]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[catalina.jar:9.0.39]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[catalina.jar:9.0.39]
        at org.apache.catalina.filters.CorsFilter.handleNonCORS(CorsFilter.java:352) ~[catalina.jar:9.0.39]
        at org.apache.catalina.filters.CorsFilter.doFilter(CorsFilter.java:171) ~[catalina.jar:9.0.39]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[catalina.jar:9

==== ticket cleanup ==
2020-11-06 10:17:32,023 TRACE [org.apereo.cas.ticket.registry.JpaTicketRegistry] - <org.hibernate.QueryException: could not resolve property: ticketGrantingTicket of: org.apereo.cas.ticket.TransientSessionTicketImpl [DELETE FROM org.apereo.cas.ticket.TransientSessionTicketImpl s WHERE s.ticketGrantingTicket.id = :id]>
java.lang.IllegalArgumentException: org.hibernate.QueryException: could not resolve property: ticketGrantingTicket of: org.apereo.cas.ticket.TransientSessionTicketImpl [DELETE FROM org.apereo.cas.ticket.TransientSessionTicketImpl s WHERE s.ticketGrantingTicket.id = :id]
        at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:138) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:188) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.AbstractSharedSessionContract.createQuery(AbstractSharedSessionContract.java:725) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.AbstractSharedSessionContract.createQuery(AbstractSharedSessionContract.java:113) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]

        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.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:314) ~[spring-orm-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at com.sun.proxy.$Proxy248.createQuery(Unknown Source) ~[?:?]
        at org.apereo.cas.ticket.registry.JpaTicketRegistry.lambda$deleteTicketGrantingTickets$6(JpaTicketRegistry.java:244) ~[cas-server-support-jpa-ticket-registry-6.2.5.jar:6.2.5]
        at java.util.stream.ReferencePipeline$4$1.accept(ReferencePipeline.java:212) ~[?:?]
        at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177) ~[?:?]
        at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
        at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?]
        at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
        at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?]
        at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
        at java.util.stream.IntPipeline.reduce(IntPipeline.java:491) ~[?:?]
        at java.util.stream.IntPipeline.sum(IntPipeline.java:449) ~[?:?]
        at org.apereo.cas.ticket.registry.JpaTicketRegistry.deleteTicketGrantingTickets(JpaTicketRegistry.java:252) ~[cas-server-support-jpa-ticket-registry-6.2.5.jar:6.2.5]
        at org.apereo.cas.ticket.registry.JpaTicketRegistry.deleteSingleTicket(JpaTicketRegistry.java:210) ~[cas-server-support-jpa-ticket-registry-6.2.5.jar:6.2.5]
        at org.apereo.cas.ticket.registry.AbstractTicketRegistry.deleteTicket(AbstractTicketRegistry.java:133) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]
        at org.apereo.cas.ticket.registry.AbstractTicketRegistry$$FastClassBySpringCGLIB$$d3c67a11.invoke(<generated>) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:687) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.apereo.cas.ticket.registry.JpaTicketRegistry$$EnhancerBySpringCGLIB$$7abb7ca6.deleteTicket(<generated>) ~[cas-server-support-jpa-ticket-registry-6.2.5.jar:6.2.5]

        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.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) ~[spring-core-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) ~[spring-cloud-context-2.2.2.RELEASE.jar:2.2.2.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at com.sun.proxy.$Proxy166.deleteTicket(Unknown Source) ~[?:?]
        at org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner.cleanTicket(DefaultTicketRegistryCleaner.java:82) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]
        at java.util.stream.ReferencePipeline$4$1.accept(ReferencePipeline.java:212) ~[?:?]
        at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177) ~[?:?]
        at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195) ~[?:?]
        at java.util.Iterator.forEachRemaining(Iterator.java:133) ~[?:?]
        at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801) ~[?:?]
        at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658) ~[?:?]
        at org.hibernate.query.spi.StreamDecorator.forEach(StreamDecorator.java:155) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:274) ~[?:?]
        at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195) ~[?:?]
        at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
        at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?]
        at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
        at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?]
        at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
        at java.util.stream.IntPipeline.reduce(IntPipeline.java:491) ~[?:?]
        at java.util.stream.IntPipeline.sum(IntPipeline.java:449) ~[?:?]
        at org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner.cleanInternal(DefaultTicketRegistryCleaner.java:69) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]
        at org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner.clean(DefaultTicketRegistryCleaner.java:45) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]
        at org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner$$FastClassBySpringCGLIB$$29f046b2.invoke(<generated>) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:771) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]

        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:366) ~[spring-tx-5.2.6.RELEASE.jar:5.2.6.RELEASE]

        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118) ~[spring-tx-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner$$EnhancerBySpringCGLIB$$f560e1c2.clean(<generated>) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]

        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.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) ~[spring-core-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) ~[spring-cloud-context-2.2.2.RELEASE.jar:2.2.2.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at com.sun.proxy.$Proxy256.clean(Unknown Source) ~[?:?]
        at org.apereo.cas.config.CasCoreTicketsSchedulingConfiguration$TicketRegistryCleanerScheduler.run(CasCoreTicketsSchedulingConfiguration.java:101) ~[cas-server-core-tickets-6.2.5.jar:6.2.5]
        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.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
        at java.lang.Thread.run(Thread.java:834) [?:?]
Caused by: org.hibernate.QueryException: could not resolve property: ticketGrantingTicket of: org.apereo.cas.ticket.TransientSessionTicketImpl [DELETE FROM org.apereo.cas.ticket.TransientSessionTicketImpl s WHERE s.ticketGrantingTicket.id = :id]
        at org.hibernate.QueryException.generateQueryException(QueryException.java:120) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.QueryException.wrapWithQueryString(QueryException.java:103) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.doCompile(QueryTranslatorImpl.java:220) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.compile(QueryTranslatorImpl.java:144) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.engine.query.spi.HQLQueryPlan.<init>(HQLQueryPlan.java:113) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.engine.query.spi.HQLQueryPlan.<init>(HQLQueryPlan.java:73) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.engine.query.spi.QueryPlanCache.getHQLQueryPlan(QueryPlanCache.java:162) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.AbstractSharedSessionContract.getQueryPlan(AbstractSharedSessionContract.java:604) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.AbstractSharedSessionContract.createQuery(AbstractSharedSessionContract.java:716) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        ... 85 more
Caused by: org.hibernate.QueryException: could not resolve property: ticketGrantingTicket of: org.apereo.cas.ticket.TransientSessionTicketImpl
        at org.hibernate.persister.entity.AbstractPropertyMapping.propertyException(AbstractPropertyMapping.java:73) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.persister.entity.AbstractPropertyMapping.toType(AbstractPropertyMapping.java:67) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.persister.entity.AbstractEntityPersister.toType(AbstractEntityPersister.java:2047) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.tree.FromElementType.getPropertyType(FromElementType.java:412) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.tree.FromElement.getPropertyType(FromElement.java:520) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.tree.DotNode.getDataType(DotNode.java:693) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.HqlSqlWalker.lookupProperty(HqlSqlWalker.java:667) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.addrExpr(HqlSqlBaseWalker.java:5068) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.expr(HqlSqlBaseWalker.java:1299) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.exprOrSubquery(HqlSqlBaseWalker.java:4771) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.comparisonExpr(HqlSqlBaseWalker.java:4237) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.logicalExpr(HqlSqlBaseWalker.java:2161) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.whereClause(HqlSqlBaseWalker.java:827) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.deleteStatement(HqlSqlBaseWalker.java:469) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.antlr.HqlSqlBaseWalker.statement(HqlSqlBaseWalker.java:289) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.analyze(QueryTranslatorImpl.java:276) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.doCompile(QueryTranslatorImpl.java:192) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.compile(QueryTranslatorImpl.java:144) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.engine.query.spi.HQLQueryPlan.<init>(HQLQueryPlan.java:113) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.engine.query.spi.HQLQueryPlan.<init>(HQLQueryPlan.java:73) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.engine.query.spi.QueryPlanCache.getHQLQueryPlan(QueryPlanCache.java:162) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.AbstractSharedSessionContract.getQueryPlan(AbstractSharedSessionContract.java:604) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        at org.hibernate.internal.AbstractSharedSessionContract.createQuery(AbstractSharedSessionContract.java:716) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
        ... 85 more

---- another snippet ----
# Error dump (ticket is not deleted, exception thrown)
^[[32m2020-11-05 14:35:14,200 INFO [org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner] - <[1] expired tickets removed.>^[[m
^[[36m2020-11-05 14:35:14,200 DEBUG [org.apereo.cas.ticket.registry.support.JpaLockingStrategy] - <Releasing [cas-ticket-registry-cleaner] lock held by [maaro].>^[[m
^[[36m2020-11-05 14:35:14,201 DEBUG [org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner] - <Finished ticket cleanup.>^[[m
^[[1;31m2020-11-05 14:35:14,219 ERROR [org.apereo.cas.config.CasCoreTicketsSchedulingConfiguration] - <Transaction silently rolled back because it has been marked as rollback-only>^[[m
org.springframework.transaction.UnexpectedRollbackException: Transaction silently rolled back because it has been marked as rollback-only
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:752) ~[spring-tx-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711) ~[spring-tx-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:631) ~[spring-tx-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:385) ~[spring-tx-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:118) ~[spring-tx-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner$$EnhancerBySpringCGLIB$$e7722c2c.clean(<generated>) ~[cas-server-core-tickets-api-6.2.5.jar:6.2.5]
        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.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:282) ~[spring-core-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.cloud.context.scope.GenericScope$LockedScopedProxyFactoryBean.invoke(GenericScope.java:499) ~[spring-cloud-context-2.2.2.RELEASE.jar:2.2.2.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at com.sun.proxy.$Proxy256.clean(Unknown Source) ~[?:?]
        at org.apereo.cas.config.CasCoreTicketsSchedulingConfiguration$TicketRegistryCleanerScheduler.run(CasCoreTicketsSchedulingConfiguration.java:101) ~[cas-server-core-tickets-6.2.5.jar:6.2.5]
        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.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.2.6.RELEASE.jar:5.2.6.RELEASE]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
        at java.lang.Thread.run(Thread.java:834) [?:?]




randomuser878

unread,
Nov 24, 2020, 3:45:04 PM11/24/20
to CAS Developer, randomuser878
It looks like I have isolated the problem but no idea how to fix it.

To precisely recreate,enable simple-mfa
    // MFA
    implementation "org.apereo.cas:cas-server-support-simple-mfa-core:${casServerVersion}"
    implementation "org.apereo.cas:cas-server-support-simple-mfa:${casServerVersion}"
.. configure default simple-mfa for email (does not really matter as the test case was not even creating a simple mfa transactions, it was a simple /cas/login and /cas/logout).

To get past the issue have to either not use simple-mfa or put back the 6.1.7.x code and have to ignore how transientsessionticket gets cleared. Unfortunately the direction is to use a simple-mfa as one of the mfa providers.

 So I am thinking there might be some discrepancy between cas simple-mfa (CASMFA) and TST for transientsessionticket but that is above my current knowledge of CAS.
  api/cas-server-core-api-ticket/src/main/java/org/apereo/cas/ticket/TransientSessionTicket.java:32:    String PREFIX = "TST";
  support/cas-server-support-simple-mfa-core/src/main/java/org/apereo/cas/mfa/simple/CasSimpleMultifactorAuthenticationTicketFactory.java:29:    public static final String PREFIX = "CASMFA";

cas 6.2.5  cas-6.2.x\support\cas-server-support-jpa-ticket-registry\src\main\java\org\apereo\cas\ticket\registry\JpaTicketRegistry.java

    /**
     * Delete ticket granting tickets.
     *
     * @param ticketId the ticket id
     * @return the total count
     */
    private int deleteTicketGrantingTickets(final String ticketId) {
        var totalCount = this.ticketCatalog.findAll()
            .stream()
            .filter(defn -> !defn.getProperties().isExcludeFromCascade())
            .mapToInt(defn -> {
                try {
                    val sql = String.format("DELETE FROM %s s WHERE s.ticketGrantingTicket.id = :id", getTicketEntityName(defn));
                    LOGGER.trace("Creating query [{}]", sql);
                    val query = entityManager.createQuery(sql);
                    query.setParameter("id", ticketId);
                    return query.executeUpdate();
                } catch (final Exception e) {
                    LOGGER.trace(e.getMessage(), e);
                }
                return 0;
            })
            .sum();

        val tgt = this.ticketCatalog.find(TicketGrantingTicket.PREFIX);
        val sql = String.format("DELETE FROM %s t WHERE t.id = :id", getTicketEntityName(tgt));
        val query = entityManager.createQuery(sql);
        query.setParameter("id", ticketId);
        totalCount += query.executeUpdate();
        return totalCount;
}

Replaced with cas 6.1.7.x code thus no longer cleaning any potential tgt related transientsessionticket but the issue at hand is isolated

private int deleteTicketGrantingTickets(final String ticketId) {
        var totalCount = 0;

        val st = this.ticketCatalog.find(ServiceTicket.PREFIX);

        val sql1 = String.format("DELETE FROM %s s WHERE s.ticketGrantingTicket.id = :id", getTicketEntityName(st));
        var query = entityManager.createQuery(sql1);
        query.setParameter("id", ticketId);
        totalCount += query.executeUpdate();

        val tgt = this.ticketCatalog.find(TicketGrantingTicket.PREFIX);
        val sql2 = String.format("DELETE FROM %s s WHERE s.ticketGrantingTicket.id = :id", getTicketEntityName(tgt));
        query = entityManager.createQuery(sql2);
        query.setParameter("id", ticketId);
        totalCount += query.executeUpdate();

        val sql3 = String.format("DELETE FROM %s t WHERE t.id = :id", getTicketEntityName(tgt));
        query = entityManager.createQuery(sql3);
        query.setParameter("id", ticketId);
        totalCount += query.executeUpdate();

        return totalCount;
}

Thanks for any ideas in where else can I look.
Reply all
Reply to author
Forward
0 new messages