I'm still getting inconsistent ST cleanup summaries using 4.2.5-SNAPSHOT with the default in memory cleaner - See the attached log.
Note that all service tickets are found for cleanup, but only two here have logged "Attempting to retrieve ticket". It appears in this version that all service tickets are found, but only are two are 'expired' at the point where the TGTs expire. Again, this is despite having st.timeToKillInSeconds=600. The default registry does 2 minutes pass per clean - the STs should all be expiring when the TGTs expire (if I'm understanding correctly) - otherwise, they should expire when timeToKillInSeconds passes. In this case 10 minutes. Assuming the STs expire on their own, I waited 10 minutes: grep "expired tickets found and removed." cas.log: 2016-08-24 16:47:21,814 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 7 expired tickets found and removed. <- 5 TGTs + 2 STs, the last line of the attached log 2016-08-24 16:49:21,714 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 16:51:21,718 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 16:53:21,723 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 16:55:21,715 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 16:57:21,712 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 16:59:21,715 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 17:01:21,717 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 17:03:21,711 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 17:05:21,711 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 17:07:21,711 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 17:09:21,711 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. 2016-08-24 17:11:21,713 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 0 expired tickets found and removed. The 3 floating STs should have expired somewhere, but don't appear to be. On Tuesday, August 23, 2016 at 8:54:29 PM UTC-7, Misagh Moayyed wrote: > > Cool. Thanks for the report. I can run some tests on this, and it would be > more reassuring if you were to switch to 4.2.5-SNAPSHOT and test the latest > patch that William has put together that handles this sort of thing. If > the problem persists, we could further review it before the official 4.2.5, > which is in about 10 days. > > In 4.2.5, the cleanup logic is shared by all registry types. So the > behavior is made consistent across all where the task of ticket removal is > then delegated to the individual registry that knows how to talk to the > source. I suggest that you run your same batch of tests against that > baseline, and if you still see the issue, please post back. > > -- > Misagh > > From: Jeffrey Wong <awo...@gmail.com> <javascript:> > Reply: Jeffrey Wong <awo...@gmail.com> <javascript:> > Date: August 23, 2016 at 2:33:34 PM > To: CAS Community <cas...@apereo.org> <javascript:> > Cc: mmoa...@unicon.net <javascript:> <mmo...@unicon.net> <javascript:> > Subject: Re: [cas-user] After a month, no tickets created in 4.2.2? > > Also to note, switching to JPA under the same circumstances, I can confirm > that all 10 tickets are consistently reporting in as cleaned (ran over > multiple tests). Definitely seems like there's something strange with the > in memory ticketing cleaner. > > On Tuesday, August 23, 2016 at 2:04:51 PM UTC-7, Jeffrey Wong wrote: >> >> Ah, looks to be that the PT fix won't affect my issues then - Let me >> clarify how I'm doing my testing in that case: >> >> I'm creating a new session (new cookie map) with every login, over the >> same user. I'm scraping the lt, execution, and _eventId off of the initial >> payload, and making a post request with those parameters with >> username+password. >> >> In the logs, each login creates a new TGT (since I'm not sharing cookies >> per request, I'll have a unique TGT per login) and a new ST. I've turned on >> debugs and can confirm that with a series of 5 logins, 5 TGT and 5 STs are >> created. I turned st.timeToKillInSeconds way down (10) to ensure cleanup of >> all tickets on the next cleaning run. In this test case above, I would >> expect a total of 10 tickets to be cleaned up on the next cleaner run. >> >> During cleanup, I appear to be missing a count of a ST or two. It >> occasionally claims between 7 and 9 tickets cleaned. I've counted all 5 >> TGTs, but the STs appear to only occasionally be cleaned up fully. >> >> To ensure that STs aren't expiring on their own somehow and are strictly >> expiring as children of TGTs, I have the following settings: >> tgt.timeToKillInSeconds=10 >> st.timeToKillInSeconds=600 >> >> It's my understanding that when a TGT gets cleaned, that all STs >> associated with that TGT are also cleaned up as well, but it doesn't appear >> that this is the case. >> >> My worry is that there's an orphaned ST in memory somewhere still >> floating around memory, which would be OK if I were ticketing through ORM, >> as I could audit active tickets directly in sql, or remove them myself. I >> think in the meantime, I'll move production ticketing to a (slower, but >> more easily auditable) ORM solution. I wanted to let you know what I'm >> seeing on my end in case this is a weird edge case in the cleaner. >> >> On Monday, August 22, 2016 at 10:13:38 PM UTC-7, Misagh Moayyed wrote: >>> >>> I hate to say this, but it depends! It depends what you mean by login, >>> and it depends what you mean by 10 :) >>> >>> Before we start to discuss the answer to the ultimate question of life, >>> the universe, and everything let me explode this a bit. >>> >>> When you log into CAS, you get a TGT. You get an SSO session. That TGT >>> remains alive so long you don’t log out and so long its expiration policy >>> says it should live. For every application you log into, you will get an >>> ST. The application ideally keeps track of the user session so it wouldn’t >>> have to ask for more STs every time you refresh its page for instance. So: >>> >>> If you log in 10 times to 10 different apps, you get 1 TGT and 10 STs. >>> If the act of logging in requires you to present credentials every time, >>> (i.e. renew=true) then that’s still in the end 1 TGTs and 10 STs active and >>> legible for clean up, because every time you generate a new TGT, the old >>> one is immediately killed and destroyed and it will not show up in the >>> clean up log. >>> >>> The cleanup process cleans expired tickets. Regardless of the ticket >>> type. Doesn’t matter of it’s a TGT, ST, OC, etc. There are many many other >>> types. All you have to remember is, if it’s expired, it gets removed at >>> certain intervals. The only exception to this rule is, proxy-tickets are >>> not removed by the clean up process when you “logout” forcefully, and this >>> something that is fixed in the next patch release, thanks to William. But >>> you’re not using PTs, so... >>> >>> -- >>> Misagh >>> >>> From: Jeffrey Wong <awo...@gmail.com> >>> Reply: Jeffrey Wong <awo...@gmail.com> >>> Date: August 22, 2016 at 3:50:03 PM >>> To: CAS Community <cas...@apereo.org> >>> Cc: mmoa...@unicon.net <mmo...@unicon.net> >>> Subject: Re: [cas-user] After a month, no tickets created in 4.2.2? >>> >>> I am not making use of proxy granting tickets, but I'll report back if >>> it's still an issue once 2.2.5 drops. >>> >>> In the version that I have currently deployed, the counts on the tickets >>> themselves seem strange to me - When I log in 10 times, that's 10 TGTs and >>> 10 STs, correct? So I should expect 20 tickets to be cleaned up, rather >>> than 15. If it's only counting TGTs, then I should have 10 tickets total. >>> >>> I've turned on debugging, and will be monitoring this issue for when it >>> happens again, and let you know what I see in the logs. Meanwhile, can you >>> confirm or correct my understanding of the current ticket cleanup log? It >>> looks pretty strange from my end. >>> >>> On Thursday, July 21, 2016 at 11:24:12 PM UTC-7, Misagh Moayyed wrote: >>>> >>>> All expired tickets are removed by the cleaner, regardless of type. >>>> Come to think of it, do you use CAS for its proxy authentication features? >>>> That *might* have something to do with it, if you do. >>>> >>>> I personally don’t know if I’d recommend switching, because I don’t >>>> know what the problem is. Generally, switching to something more robust >>>> and >>>> distributed is a good idea, but if the problem is something else, it will >>>> simply repeat and your new registry will have done nothing to fix it. I >>>> would instead turn up logs, load test as much as possible and keep it >>>> running under test for some time. Observe. >>>> >>>> -- >>>> Misagh >>>> >>>> From: Jeffrey Wong <awo...@gmail.com> >>>> Reply: Jeffrey Wong <awo...@gmail.com> >>>> Date: July 20, 2016 at 3:27:17 PM >>>> To: CAS Community <cas...@apereo.org> >>>> Cc: mmoa...@unicon.net <mmo...@unicon.net> >>>> Subject: Re: [cas-user] After a month, no tickets created in 4.2.2? >>>> >>>> Grepping through what I have, I can confirm that the tickets are being >>>> removed, as I do have log statements like the following: >>>> >>>> catalina.out.2.gz:2016-07-08 22:19:31,948 INFO >>>> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <1 expired tickets >>>> found and removed.> >>>> catalina.out.2.gz:2016-07-08 22:21:32,004 INFO >>>> [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - <2 expired tickets >>>> found and removed.> >>>> >>>> I'm using the default in memory registry, the default >>>> tgt.maxTimeToLiveInSeconds + tgt.timeToKillInSeconds. >>>> st.timeToKillInSeconds=60. >>>> >>>> Other pretty bare bones defaults: >>>> >>>> <alias name="serviceThemeResolver" alias="themeResolver" /> >>>> >>>> >>>> >>>> <alias name="jsonServiceRegistryDao" alias="serviceRegistryDao" /> >>>> >>>> >>>> >>>> <alias name="defaultTicketRegistry" alias="ticketRegistry" /> >>>> >>>> >>>> >>>> <alias name="ticketGrantingTicketExpirationPolicy" >>>> alias="grantingTicketExpirationPolicy" /> >>>> <alias name="multiTimeUseOrTimeoutExpirationPolicy" >>>> alias="serviceTicketExpirationPolicy" /> >>>> <alias name="anyAuthenticationPolicy" alias="authenticationPolicy" /> >>>> >>>> >>>> >>>> <alias name="acceptAnyAuthenticationPolicyFactory" >>>> alias="authenticationPolicyFactory" /> >>>> >>>> Would you recommend perhaps a different ticket registry at this point >>>> perhaps? I don't think I'm hitting the maximum amount of tickets that the >>>> default ticket registry can hold by any means, since the maximum amount of >>>> tickets I'm seeing expire is 20. Mostly it's between 0-2 tickets that are >>>> expired, so I very much doubt the tickets being the memory bottleneck. >>>> >>>> --- >>>> >>>> Before I posted the above, I dug a little and noticed a strange ~200 >>>> tickets being cleaned up a bit before the issue (an uptick in cleanup >>>> tickets). Perhaps moving to a more robust ticket registry (not just in >>>> memory) might actually help to mitigate then. >>>> >>>> Are service tickets also being cleaned up with the same default ticket >>>> registry? What tickets should show up in that 'expired' count? TGT only, >>>> or >>>> TGT + STs? >>>> >>>> For testing, I logged in to a test instance where the tgt expirey was >>>> set to 10 seconds. 10 times: 15 expired tickets. I logged in 20 times. 29 >>>> expired tickets. >>>> >>>> What other items are included in the expired count? >>>> >>>> On Wednesday, July 20, 2016 at 2:31:37 AM UTC-7, Misagh Moayyed wrote: >>>>> >>>>> Does your log show that tickets are cleaned up successfully? Is your >>>>> expiration policy set up to allow the cleaner to expire and clean tickets >>>>> successfully? >>>>> >>>>> Without logs, it’s just a guessing game. My bet is, somehow you’ve run >>>>> out of memory. >>>>> >>>>> -- >>>>> Misagh >>>>> >>>>> From: Jeffrey Wong <awo...@gmail.com> >>>>> Reply: Jeffrey Wong <awo...@gmail.com> >>>>> Date: July 19, 2016 at 3:10:05 PM >>>>> To: CAS Community <cas...@apereo.org> >>>>> Subject: [cas-user] After a month, no tickets created in 4.2.2? >>>>> >>>>> After about a month of working perfectly on 4.2.2 deployed to tomcat7, >>>>> running under java8, randomly the in-memory ticketing system would not >>>>> create any more tickets. Restarting the tomcat instance fixed it, but I'm >>>>> wondering why CAS would randomly break on me after working so well! Using >>>>> a >>>>> LDAP (AD) backed user base with a mysql backed attribute DB. We have >>>>> pretty >>>>> minimal traffic, so I'm not sure why I am seeing issues after such a >>>>> small >>>>> amount of time. >>>>> >>>>> Despite having an <AsyncRoot level="error">, no errors have been >>>>> thrown at the time of issue. >>>>> >>>>> Unfortunately, I've only had the org.springframework.jdbc logger set >>>>> to debug, and all others at info, so I have very minimal logging around >>>>> the >>>>> issue. >>>>> >>>>> I'm noticing both the ldap auth AND the jdbc handlers returning >>>>> without issues (no errors). ...But no tickets? >>>>> >>>>> Here's a sample of the logs: >>>>> >>>>> 2016-07-19 16:28:16,399 INFO >>>>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - >>>>> <LdapAuthenticationHandler successfully authenticated user1> >>>>> 2016-07-19 16:28:16,400 DEBUG >>>>> [org.springframework.jdbc.core.JdbcTemplate] - <Executing prepared >>>>> SQL query> >>>>> 2016-07-19 16:28:16,400 DEBUG >>>>> [org.springframework.jdbc.core.JdbcTemplate] - <Executing prepared >>>>> SQL statement[SELECT ID,username,FirstName,LastName,Email FROM User >>>>> WHERE UserName = ?]> >>>>> 2016-07-19 16:28:16,400 DEBUG >>>>> [org.springframework.jdbc.datasource.DataSourceUtils] - <Fetching >>>>> JDBC Connection from DataSource> >>>>> 2016-07-19 16:28:16,401 DEBUG >>>>> [org.springframework.jdbc.datasource.DataSourceUtils] - <Returning >>>>> JDBC Connection to DataSource> >>>>> 2016-07-19 16:28:19,015 INFO >>>>> [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - >>>>> <LdapAuthenticationHandler successfully authenticated user2> >>>>> 2016-07-19 16:28:19,015 DEBUG >>>>> [org.springframework.jdbc.core.JdbcTemplate] - <Executing prepared >>>>> SQL query> >>>>> 2016-07-19 16:28:19,015 DEBUG >>>>> [org.springframework.jdbc.core.JdbcTemplate] - <Executing prepared >>>>> SQL statement[SELECT ID,username,FirstName,LastName,Email FROM User >>>>> WHERE UserName = ?]> >>>>> 2016-07-19 16:28:19,015 DEBUG >>>>> [org.springframework.jdbc.datasource.DataSourceUtils] - <Fetching >>>>> JDBC Connection from DataSource> >>>>> 2016-07-19 16:28:19,017 DEBUG >>>>> [org.springframework.jdbc.datasource.DataSourceUtils] - <Returning >>>>> JDBC Connection to DataSource> >>>>> >>>>> Immediately before this, I've seen tickets that are created (an audit >>>>> log is posted that a ticket granting ticket has been created and >>>>> validated, >>>>> and all is good). There are no exceptions thrown between when the tickets >>>>> were able to be created and when there was this bottleneck. >>>>> >>>>> On the front end, after the logs say 'success' without a ticket >>>>> created, they are redirected to the main cas login page. Reproducing >>>>> this is also difficult as it will stop intermittently, without >>>>> warning. >>>>> >>>>> What are the best ways to debug or resolve these sorts of issues? What >>>>> could be causing this issue? >>>>> >>>>> Thanks in advance, >>>>> Jeff >>>>> -- >>>>> 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 cas-user+u...@apereo.org. >>>>> To post to this group, send email to cas-...@apereo.org. >>>>> Visit this group at >>>>> https://groups.google.com/a/apereo.org/group/cas-user/. >>>>> To view this discussion on the web visit >>>>> https://groups.google.com/a/apereo.org/d/msgid/cas-user/23b96c4d-0997-4da1-9051-7ddf1560e8bb%40apereo.org >>>>> >>>>> <https://groups.google.com/a/apereo.org/d/msgid/cas-user/23b96c4d-0997-4da1-9051-7ddf1560e8bb%40apereo.org?utm_medium=email&utm_source=footer> >>>>> . >>>>> For more options, visit >>>>> https://groups.google.com/a/apereo.org/d/optout. >>>>> >>>>> -- >>>> 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 cas-user+u...@apereo.org. >>>> To post to this group, send email to cas-...@apereo.org. >>>> Visit this group at >>>> https://groups.google.com/a/apereo.org/group/cas-user/. >>>> To view this discussion on the web visit >>>> https://groups.google.com/a/apereo.org/d/msgid/cas-user/c879c072-5844-48af-8d62-ce868f6c738e%40apereo.org >>>> >>>> <https://groups.google.com/a/apereo.org/d/msgid/cas-user/c879c072-5844-48af-8d62-ce868f6c738e%40apereo.org?utm_medium=email&utm_source=footer> >>>> . >>>> For more options, visit https://groups.google.com/a/apereo.org/d/optout >>>> . >>>> >>>> -- >>> 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 cas-user+u...@apereo.org. >>> To post to this group, send email to cas-...@apereo.org. >>> Visit this group at >>> https://groups.google.com/a/apereo.org/group/cas-user/. >>> To view this discussion on the web visit >>> https://groups.google.com/a/apereo.org/d/msgid/cas-user/d37ce2b3-3d16-437d-8b9b-8d243f38237c%40apereo.org >>> >>> <https://groups.google.com/a/apereo.org/d/msgid/cas-user/d37ce2b3-3d16-437d-8b9b-8d243f38237c%40apereo.org?utm_medium=email&utm_source=footer> >>> . >>> For more options, visit https://groups.google.com/a/apereo.org/d/optout. >>> >>> -- > 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 cas-user+u...@apereo.org <javascript:>. > To post to this group, send email to cas-...@apereo.org <javascript:>. > Visit this group at https://groups.google.com/a/apereo.org/group/cas-user/ > . > To view this discussion on the web visit > https://groups.google.com/a/apereo.org/d/msgid/cas-user/ccf91db7-b2c6-47bb-b4a9-1f269e01dc66%40apereo.org > > <https://groups.google.com/a/apereo.org/d/msgid/cas-user/ccf91db7-b2c6-47bb-b4a9-1f269e01dc66%40apereo.org?utm_medium=email&utm_source=footer> > . > For more options, visit https://groups.google.com/a/apereo.org/d/optout. > > -- 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 cas-user+unsubscr...@apereo.org. To post to this group, send email to cas-user@apereo.org. Visit this group at https://groups.google.com/a/apereo.org/group/cas-user/. To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/3ea99762-8912-4812-b892-49b76529f90e%40apereo.org. For more options, visit https://groups.google.com/a/apereo.org/d/optout.
2016-08-24 16:47:21,721 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Beginning ticket cleanup... 2016-08-24 16:47:21,722 DEBUG [org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy] - Ticket is expired because the time since last use is greater than timeToKillInMilliseconds 2016-08-24 16:47:21,722 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Cleaning up expired ticket-granting ticket [TGT-**********************************************ORihpOIfmS-DEVTESTING] 2016-08-24 16:47:21,723 DEBUG [org.jasig.cas.util.RegexUtils] - Pattern ^(https|imaps|http)://.* is a valid regex. 2016-08-24 16:47:21,724 DEBUG [org.jasig.cas.logout.SamlCompliantLogoutMessageCreator] - Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-7-XffbXR6FzzdFQvespDrnzoIRD0VcldwFX4B" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-7-d0znIX1SQlWjde4tMl9Z-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>] 2016-08-24 16:47:21,724 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Sending logout request for: [http://devtesting.company.com/] 2016-08-24 16:47:21,726 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Prepared logout message to send is [org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@6002741c[url=http://devtesting.company.com/,message=<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-7-XffbXR6FzzdFQvespDrnzoIRD0VcldwFX4B" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-7-d0znIX1SQlWjde4tMl9Z-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>,asynchronous=true,contentType=application/x-www-form-urlencoded]] 2016-08-24 16:47:21,731 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Captured logout request [org.jasig.cas.logout.DefaultLogoutRequest@31b6bc8a[ticketId=ST-7-d0znIX1SQlWjde4tMl9Z-DEVTESTING,service=http://devtesting.company.com/,status=SUCCESS]] 2016-08-24 16:47:21,731 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to retrieve ticket [TGT-**********************************************ORihpOIfmS-DEVTESTING] 2016-08-24 16:47:21,731 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket [TGT-**********************************************ORihpOIfmS-DEVTESTING] found in registry. 2016-08-24 16:47:21,731 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing children of ticket [TGT-**********************************************ORihpOIfmS-DEVTESTING] from the registry. 2016-08-24 16:47:21,731 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removed ticket [ST-7-d0znIX1SQlWjde4tMl9Z-DEVTESTING] 2016-08-24 16:47:21,732 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing ticket [TGT-**********************************************ORihpOIfmS-DEVTESTING] from the registry. 2016-08-24 16:47:21,732 DEBUG [org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy] - Ticket is expired because the time since last use is greater than timeToKillInMilliseconds 2016-08-24 16:47:21,732 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Cleaning up expired service ticket [ST-7-d0znIX1SQlWjde4tMl9Z-DEVTESTING] 2016-08-24 16:47:21,732 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to retrieve ticket [ST-7-d0znIX1SQlWjde4tMl9Z-DEVTESTING] 2016-08-24 16:47:21,732 DEBUG [org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy] - Ticket is expired because the time since last use is greater than timeToKillInMilliseconds 2016-08-24 16:47:21,733 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Cleaning up expired ticket-granting ticket [TGT-**********************************************wRykEwtwpD-DEVTESTING] 2016-08-24 16:47:21,736 DEBUG [org.jasig.cas.logout.SamlCompliantLogoutMessageCreator] - Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-8-JxqVw1dh0wVBOatTzDw6YEpOTtu4dnX9oZh" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-8-wc5MeCwd5g61yHVmJQUO-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>] 2016-08-24 16:47:21,736 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Sending logout request for: [http://devtesting.company.com/] 2016-08-24 16:47:21,742 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Prepared logout message to send is [org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@3a06bd10[url=http://devtesting.company.com/,message=<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-8-JxqVw1dh0wVBOatTzDw6YEpOTtu4dnX9oZh" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-8-wc5MeCwd5g61yHVmJQUO-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>,asynchronous=true,contentType=application/x-www-form-urlencoded]] 2016-08-24 16:47:21,748 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Captured logout request [org.jasig.cas.logout.DefaultLogoutRequest@312e59de[ticketId=ST-8-wc5MeCwd5g61yHVmJQUO-DEVTESTING,service=http://devtesting.company.com/,status=SUCCESS]] 2016-08-24 16:47:21,748 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to retrieve ticket [TGT-**********************************************wRykEwtwpD-DEVTESTING] 2016-08-24 16:47:21,748 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket [TGT-**********************************************wRykEwtwpD-DEVTESTING] found in registry. 2016-08-24 16:47:21,748 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing children of ticket [TGT-**********************************************wRykEwtwpD-DEVTESTING] from the registry. 2016-08-24 16:47:21,748 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removed ticket [ST-8-wc5MeCwd5g61yHVmJQUO-DEVTESTING] 2016-08-24 16:47:21,748 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing ticket [TGT-**********************************************wRykEwtwpD-DEVTESTING] from the registry. 2016-08-24 16:47:21,748 DEBUG [org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy] - Ticket is expired because the time since last use is greater than timeToKillInMilliseconds 2016-08-24 16:47:21,749 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Cleaning up expired ticket-granting ticket [TGT-***********************************************teCkVpN9qO-DEVTESTING] 2016-08-24 16:47:21,756 DEBUG [org.jasig.cas.logout.SamlCompliantLogoutMessageCreator] - Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-9-rG7byVOrrDMidZkjbJ2orCYnEFaOnNzT1Td" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-10-iQfhCt1QHJsJLiyuyFJW-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>] 2016-08-24 16:47:21,756 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Sending logout request for: [http://devtesting.company.com/] 2016-08-24 16:47:21,756 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Prepared logout message to send is [org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@35f8e19d[url=http://devtesting.company.com/,message=<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-9-rG7byVOrrDMidZkjbJ2orCYnEFaOnNzT1Td" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-10-iQfhCt1QHJsJLiyuyFJW-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>,asynchronous=true,contentType=application/x-www-form-urlencoded]] 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Captured logout request [org.jasig.cas.logout.DefaultLogoutRequest@4f5dced8[ticketId=ST-10-iQfhCt1QHJsJLiyuyFJW-DEVTESTING,service=http://devtesting.company.com/,status=SUCCESS]] 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to retrieve ticket [TGT-***********************************************teCkVpN9qO-DEVTESTING] 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket [TGT-***********************************************teCkVpN9qO-DEVTESTING] found in registry. 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing children of ticket [TGT-***********************************************teCkVpN9qO-DEVTESTING] from the registry. 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removed ticket [ST-10-iQfhCt1QHJsJLiyuyFJW-DEVTESTING] 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing ticket [TGT-***********************************************teCkVpN9qO-DEVTESTING] from the registry. 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy] - Ticket is expired because the time since last use is greater than timeToKillInMilliseconds 2016-08-24 16:47:21,759 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Cleaning up expired ticket-granting ticket [TGT-**********************************************exn7wPy2Cc-DEVTESTING] 2016-08-24 16:47:21,772 DEBUG [org.jasig.cas.logout.SamlCompliantLogoutMessageCreator] - Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-10-Bpr9oX0DtiuWLNZIgUBFP7sQ53lJqOfdGXY" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-6-CQaKStn4BbPZ1snamewK-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>] 2016-08-24 16:47:21,772 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Sending logout request for: [http://devtesting.company.com/] 2016-08-24 16:47:21,773 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Prepared logout message to send is [org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@cfe8e44[url=http://devtesting.company.com/,message=<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-10-Bpr9oX0DtiuWLNZIgUBFP7sQ53lJqOfdGXY" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-6-CQaKStn4BbPZ1snamewK-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>,asynchronous=true,contentType=application/x-www-form-urlencoded]] 2016-08-24 16:47:21,774 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Captured logout request [org.jasig.cas.logout.DefaultLogoutRequest@d3218d3[ticketId=ST-6-CQaKStn4BbPZ1snamewK-DEVTESTING,service=http://devtesting.company.com/,status=SUCCESS]] 2016-08-24 16:47:21,774 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to retrieve ticket [TGT-**********************************************exn7wPy2Cc-DEVTESTING] 2016-08-24 16:47:21,777 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket [TGT-**********************************************exn7wPy2Cc-DEVTESTING] found in registry. 2016-08-24 16:47:21,778 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing children of ticket [TGT-**********************************************exn7wPy2Cc-DEVTESTING] from the registry. 2016-08-24 16:47:21,779 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removed ticket [ST-6-CQaKStn4BbPZ1snamewK-DEVTESTING] 2016-08-24 16:47:21,782 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing ticket [TGT-**********************************************exn7wPy2Cc-DEVTESTING] from the registry. 2016-08-24 16:47:21,783 DEBUG [org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy] - Ticket is expired because the time since last use is greater than timeToKillInMilliseconds 2016-08-24 16:47:21,783 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Cleaning up expired ticket-granting ticket [TGT-***********************************************rotjfYiWnc-DEVTESTING] 2016-08-24 16:47:21,792 DEBUG [org.jasig.cas.logout.SamlCompliantLogoutMessageCreator] - Generated logout message: [<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-11-LdudOp3CFJciBGKE9sGpGXLDb2MiVbVaBjd" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-9-s9eci06XvKuCAcZULczJ-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>] 2016-08-24 16:47:21,794 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Sending logout request for: [http://devtesting.company.com/] 2016-08-24 16:47:21,795 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Prepared logout message to send is [org.jasig.cas.logout.LogoutManagerImpl$LogoutHttpMessage@2cb83ca3[url=http://devtesting.company.com/,message=<samlp:LogoutRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" ID="LR-11-LdudOp3CFJciBGKE9sGpGXLDb2MiVbVaBjd" Version="2.0" IssueInstant="2016-08-24T16:47:21Z"><saml:NameID xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">@NOT_USED@</saml:NameID><samlp:SessionIndex>ST-9-s9eci06XvKuCAcZULczJ-DEVTESTING</samlp:SessionIndex></samlp:LogoutRequest>,asynchronous=true,contentType=application/x-www-form-urlencoded]] 2016-08-24 16:47:21,803 DEBUG [org.jasig.cas.logout.LogoutManagerImpl] - Captured logout request [org.jasig.cas.logout.DefaultLogoutRequest@699be102[ticketId=ST-9-s9eci06XvKuCAcZULczJ-DEVTESTING,service=http://devtesting.company.com/,status=SUCCESS]] 2016-08-24 16:47:21,803 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to retrieve ticket [TGT-***********************************************rotjfYiWnc-DEVTESTING] 2016-08-24 16:47:21,803 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Ticket [TGT-***********************************************rotjfYiWnc-DEVTESTING] found in registry. 2016-08-24 16:47:21,803 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing children of ticket [TGT-***********************************************rotjfYiWnc-DEVTESTING] from the registry. 2016-08-24 16:47:21,804 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removed ticket [ST-9-s9eci06XvKuCAcZULczJ-DEVTESTING] 2016-08-24 16:47:21,806 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Removing ticket [TGT-***********************************************rotjfYiWnc-DEVTESTING] from the registry. 2016-08-24 16:47:21,807 DEBUG [org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy] - Ticket is expired because the time since last use is greater than timeToKillInMilliseconds 2016-08-24 16:47:21,807 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Cleaning up expired service ticket [ST-9-s9eci06XvKuCAcZULczJ-DEVTESTING] 2016-08-24 16:47:21,807 DEBUG [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - Attempting to retrieve ticket [ST-9-s9eci06XvKuCAcZULczJ-DEVTESTING] 2016-08-24 16:47:21,814 INFO [org.jasig.cas.ticket.registry.DefaultTicketRegistry] - 7 expired tickets found and removed.
