We're trying to troubleshoot an intermittent problem some of our users have been reporting with CAS5 (RC4). The behavior being reported is that that after providing their credentials at the login page, they are simply returned to the login page again with no error. Unfortunately we have not yet been able to reliably reproduce the problem.
It appears from the logs that the user may be attempting to access the app with an invalid TGT. It's not clear to me how or where the TGT is being "mishandled" though. I've pulled a couple of incidents from out logs: ################# ##### user1 ##### ################# User1 logs in and is issued a TGT 2016-11-29 09:25:27,647 INFO [org.apereo.cas.adaptors.duo.authn.web.DuoAuthenticationHandler] - <Successful Duo authentication for [user1]> 2016-11-29 09:25:27,647 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <DuoAuthenticationHandler successfully authenticated org.apereo.cas.adaptors.duo.authn.web.DuoCredential@10xxxxx8[username=user1,signedDuoResponse=AUTH|dGxx...xx]> 2016-11-29 09:25:27,663 DEBUG [org.apereo.cas.ticket.registry.DefaultTicketRegistry] - <Added ticket [TGT-***************************************************PwWjCaS35u-cas01] to registry.> User1 logs in again later is issued a new TGT 2016-11-29 15:17:41,553 INFO [org.apereo.cas.adaptors.duo.authn.web.DuoAuthenticationHandler] - <Successful Duo authentication for [user1]> 2016-11-29 15:17:41,554 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <DuoAuthenticationHandler successfully authenticated org.apereo.cas.adaptors.duo.authn.web.DuoCredential@1cxxxxx9[username=user1,signedDuoResponse=AUTH|dGxx...xx]> 2016-11-29 15:17:41,570 DEBUG [org.apereo.cas.ticket.registry.DefaultTicketRegistry] - <Added ticket [TGT-***************************************************DbtsqgSBiQ-cas01] to registry.> A ST is successfully granted and validated using that TGT 2016-11-29 15:17:41,585 INFO [org.apereo.cas.CentralAuthenticationServiceImpl] - <Granted ticket [ST-302853-XDJDK6Jgwx5MnntO5cPU-cas01] for service [https://www.hawaii.edu/casl2/login?service=https%3A%2F%2Ffoo.hawaii.edu%2Fkfs-prd%2Fportal.do&renew=true] and principal [user1]> 2016-11-29 15:17:41,585 DEBUG [org.apereo.cas.CentralAuthenticationServiceImpl] - <Publishing org.apereo.cas.support.events.CasServiceTicketGrantedEvent@30a6f889[ticketGrantingTicket=TGT-***************************************************DbtsqgSBiQ-cas01,serviceTicket=ST-302853-XDJxxxxxwx5MnntO5cPU-PwWjCaS35ucas01]> 2016-11-29 15:17:41,611 DEBUG [org.apereo.cas.CentralAuthenticationServiceImpl] - <Publishing org.apereo.cas.support.events.CasServiceTicketValidatedEvent@157c27ed[assertion=org.apereo.cas.authentication.DefaultAuthentication@99a0bcfc:https://www.hawaii.edu/casl2/login?service=https%3A%2F%2Ffoo.hawaii.edu%2Fkfs-prd%2Fportal.do&renew=true,serviceTicket=ST-302853-XDJDK6Jgwx5MnntO5cPU-cas01]> A short while later, there's a different AuthN for the same app (LDAP vs Duo?), but CAS fails to issue a ST 2016-11-29 15:33:24,106 DEBUG [org.apereo.cas.web.support.DefaultArgumentExtractor] - <Created https://www.hawaii.edu/casl2/login?service=https%3A%2F%2Ffoo.hawaii.edu%2Fkfs-prd%2Fportal.do%3FchannelTitle%3DAction%2520List%26channelUrl%3Dhttps%3A%2F%2Ffoo.hawaii.edu%2Fkfs-prd%2Fkew%2FActionList.do&renew=true based on org.apereo.cas.authentication.principal.WebApplicationServiceFactory@324cde8c> 2016-11-29 15:33:24,122 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler successfully authenticated user1> 2016-11-29 15:33:24,126 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Building an authentication result for authentication org.apereo.cas.authentication.DefaultAuthentication@1d736a2 and service https://www.hawaii.edu/casl2/login?service=https%3A%2F%2Ffoo.hawaii.edu%2Fkfs-prd%2Fportal.do%3FchannelTitle%3DAction%2520List%26channelUrl%3Dhttps%3A%2F%2Ffoo.hawaii.edu%2Fkfs-prd%2Fkew%2FActionList.do&renew=true> 2016-11-29 15:33:24,126 DEBUG [org.apereo.cas.CentralAuthenticationServiceImpl] - <Ticket [TGT-***************************************************PwWjCaS35u-cas01] by type [TicketGrantingTicket] cannot be found in the ticket registry.> Note that it is attempting to use the old TGT. I can't find evidence in the logs that the old PwWjCaS35u-cas01 ticket was removed. I think it is at this point that the user is returned to the login screen again. I find this general sequence of events repeated in the logs. Service tickets are not issued, and always correlated with the DEBUG that the "TGT-***PwWjCaS35u-cas01] by type [TicketGrantingTicket] cannot be found". ################# ##### user2 ##### ################# User2 logs in and is issues a TGT 2016-11-29 14:50:49,891 INFO [org.apereo.cas.adaptors.duo.authn.web.DuoAuthenticationHandler] - <Successful Duo authentication for [user2]> 2016-11-29 14:50:49,891 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <DuoAuthenticationHandler successfully authenticated org.apereo.cas.adaptors.duo.authn.web.DuoCredential@7b0b2d05[username=user2,signedDuoResponse=AUTH|dGxx...xx]> 2016-11-29 14:50:49,909 DEBUG [org.apereo.cas.ticket.registry.DefaultTicketRegistry] - <Added ticket [TGT-***************************************************10Ro5btR3h-cas01] to registry.> Later, user2's TGT expires 2016-11-29 16:50:57,777 DEBUG [org.apereo.cas.ticket.registry.DefaultTicketRegistryCleaner] - <Cleaning up expired ticket-granting ticket [TGT-***************************************************10Ro5btR3h-cas01]> 2016-11-29 16:50:57,777 INFO [org.apereo.cas.logout.LogoutManagerImpl] - <Performing logout operations for [TGT-***************************************************10Ro5btR3h-cas01]> 2016-11-29 16:50:57,779 INFO [org.apereo.cas.logout.LogoutManagerImpl] - <There are no proxy-granting tickets associated with [TGT-***************************************************10Ro5btR3h-cas01] to process for single logout> 2016-11-29 16:50:57,779 INFO [org.apereo.cas.logout.LogoutManagerImpl] - <1 logout requests were processed> 2016-11-29 16:50:57,779 DEBUG [org.apereo.cas.ticket.registry.DefaultTicketRegistry] - <Removing children of ticket [TGT-***************************************************10Ro5btR3h-cas01] from the registry.> 2016-11-29 16:50:57,779 DEBUG [org.apereo.cas.ticket.registry.DefaultTicketRegistry] - <Removing ticket [TGT-***************************************************10Ro5btR3h-cas01] from the registry.> The following day, user2 attempt to access a different app, again this time via LDAP and not Duo? 2016-11-30 06:19:09,954 DEBUG [org.apereo.cas.web.support.DefaultArgumentExtractor] - <Created https://bar.hawaii.edu/support/login/verify.php based on org.apereo.cas.authentication.principal.WebApplicationServiceFactory@324cde8c> 2016-11-30 06:19:09,978 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler successfully authenticated user2> I can't find evidence in the logs that a new TGT is issued to user2. CAS fails to issue a ST 2016-11-30 06:19:09,982 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Building an authentication result for authentication org.apereo.cas.authentication.DefaultAuthentication@e8xxxxxe and service https://bar.hawaii.edu/support/login/verify.php> 2016-11-30 06:19:09,982 DEBUG [org.apereo.cas.CentralAuthenticationServiceImpl] - <Ticket [TGT-***************************************************10Ro5btR3h-cas01] by type [TicketGrantingTicket] cannot be found in the ticket registry.> Again I note that it's trying to use the expired TGT. At this point user2 is returned to the the login screen and the cycle repeats. Are we even on the the right track focusing on the TGTs? The only thing we do know for sure is that if the users open a new icognito/private browser window, the login process works reliably as expected. User1 reports that clearing her cache does not help, and that switching tabs can prevent the loop. However, user2 reports that the problem seems more prevalent when using different tabs. I'm not sure we have enough of a sample size to make any definitive judgements about this. FWIW, I think user1 is using Firefox on Windows for her browser, and user2 is using Safari on MacOS. Any suggestions or insight into these problems would be greatly appreciated. Aloha, -baron -- Baron Fujimoto <[email protected]> :: UH Information Technology Services minutas cantorum, minutas balorum, minutas carboratum desendus pantorum -- - CAS gitter chatroom: https://gitter.im/apereo/cas - CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html - CAS documentation website: https://apereo.github.io/cas - CAS project website: https://github.com/apereo/cas --- You received this message because you are subscribed to the Google Groups "CAS Community" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/20161203011338.gx6spjba2rkqw3e7%40praenomen.mgt.hawaii.edu.
