In case anyone else encounters this or for future reference, we were able to isolate and replicate the problem, and it's now being tracked here: <https://github.com/apereo/cas/issues/2209>
On Fri, Dec 02, 2016 at 03:13:39PM -1000, Baron Fujimoto wrote: >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. -- 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/20161215223619.c5znzazoe3c65ylg%40praenomen.mgt.hawaii.edu.
