Re: [cas-user] CAS 4.0.0-RC4 not generating service tickets

Tue, 22 Apr 2014 04:03:53 -0700 

Ooh, I fixed something.

Apparently I broke something in cas-servlet.xml

I'll get back to you guys when I know more.

Regards,

Stephan

On 22/04/14 12:44, Stephan Arts wrote:

Oh, this is the startup log for tomcat/cas.
INFO: Deploying web application archive /local/scratch/apache-tomcat-7.0.53/webapps/cas.war 2014-04-22 11:47:20,869 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <serviceTicketsCache.maxElementsInMemory=10000> 2014-04-22 11:47:20,869 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <serviceTicketsCache.maxElementsOnDisk=100> 2014-04-22 11:47:20,869 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <serviceTicketsCache.isOverflowToDisk=false> 2014-04-22 11:47:20,869 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <serviceTicketsCache.timeToLive=300> 2014-04-22 11:47:20,869 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <serviceTicketsCache.timeToIdle=0> 2014-04-22 11:47:20,870 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <serviceTicketsCache.cacheManager=ticketRegistryCacheManager> 2014-04-22 11:47:20,870 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <ticketGrantingTicketsCache.maxElementsInMemory=10000> 2014-04-22 11:47:20,870 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <ticketGrantingTicketsCache.maxElementsOnDisk=10000000> 2014-04-22 11:47:20,870 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <ticketGrantingTicketsCache.isOverflowToDisk=true> 2014-04-22 11:47:20,870 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <ticketGrantingTicketsCache.timeToLive=0> 2014-04-22 11:47:20,870 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <ticketGrantingTicketsCache.timeToIdle=7201> 2014-04-22 11:47:20,870 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <ticketGrantingTicketsCache.cacheManager=ehCacheTicketRegistryCache> 2014-04-22 11:47:21,140 DEBUG [org.jasig.cas.services.DefaultServicesManagerImpl] - <Adding registered service ^(https?|imaps?)://.*> 2014-04-22 11:47:21,140 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Loaded 1 services.> 2014-04-22 11:47:21,738 DEBUG [org.jasig.cas.util.AutowiringSchedulerFactoryBean] - <Autowired the following triggers defined in application context: [periodicServiceRegistryReloaderTrigger]> 2014-04-22 11:47:22,290 INFO [org.jasig.cas.util.AutowiringSchedulerFactoryBean] - <Starting Quartz Scheduler now> Apr 22, 2014 11:47:22 AM org.apache.catalina.startup.HostConfig deployDirectory INFO: Deploying web application directory /local/scratch/apache-tomcat-7.0.53/webapps/host-manager Apr 22, 2014 11:47:22 AM org.apache.catalina.startup.HostConfig deployDirectory INFO: Deploying web application directory /local/scratch/apache-tomcat-7.0.53/webapps/ROOT Apr 22, 2014 11:47:22 AM org.apache.catalina.startup.HostConfig deployDirectory INFO: Deploying web application directory /local/scratch/apache-tomcat-7.0.53/webapps/manager 
Apr 22, 2014 11:47:22 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Apr 22, 2014 11:47:22 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8443"]
Apr 22, 2014 11:47:22 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Apr 22, 2014 11:47:22 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 9297 ms
2014-04-22 11:47:30,050 INFO [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Setting path for cookies to: /cas/> 2014-04-22 11:47:30,052 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor] - <Extractor generated service for: http://cosmos.esa.int> Apr 22, 2014 11:47:31 AM org.apache.jasper.compiler.TldLocationsCache tldScanJar INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time. 2014-04-22 11:47:32,171 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor] - <Extractor generated service for: http://cosmos.esa.int> 

Regards,

Stephan

On 22/04/14 12:42, Stephan Arts wrote:

I just enabled debugging.
I test it with no service= definition, and with service=http://cosmos.esa.int 

I still have the default wildcard service-definition in place.

Now I see the following:
2014-04-22 11:51:21,228 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Reloading registered services.> 2014-04-22 11:51:21,228 DEBUG [org.jasig.cas.services.DefaultServicesManagerImpl] - <Adding registered service ^(https?|imaps?)://.*> 2014-04-22 11:51:21,228 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Loaded 1 services.> 2014-04-22 11:51:48,054 DEBUG [org.jasig.cas.authentication.LdapAuthenticationHandler] - <Attempting LDAP authentication for sarts+password> 2014-04-22 11:51:48,071 DEBUG [org.jasig.cas.authentication.LdapAuthenticationHandler] - <LDAP response: [org.ldaptive.auth.AuthenticationResponse@729586707::authenticationResultCode=AUTHENTICATION_HANDLER_SUCCESS,<snip> accountState=null, result=true, resultCode=SUCCESS, message=null, controls=null]> 2014-04-22 11:51:48,072 DEBUG [org.jasig.cas.authentication.LdapAuthenticationHandler] - <Found principal attribute: [mail[[email protected]]]> 2014-04-22 11:51:48,072 INFO [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler successfully authenticated sarts+password> 2014-04-22 11:51:48,072 DEBUG [org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver] - <Attempting to resolve a principal...> 2014-04-22 11:51:48,072 DEBUG [org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver] - <Creating SimplePrincipal for [sarts]> 2014-04-22 11:51:48,072 DEBUG [org.jasig.cas.persondir.LdapPersonAttributeDao] - <Created seed map='{username=[sarts]}' for uid='sarts'> 2014-04-22 11:51:48,072 DEBUG [org.jasig.cas.persondir.LdapPersonAttributeDao] - <Adding attribute 'username' with value '[sarts]' to query builder 'null'> 2014-04-22 11:51:48,072 DEBUG [org.jasig.cas.persondir.LdapPersonAttributeDao] - <Constructed LDAP search query [uid=sarts]> 2014-04-22 11:51:48,072 DEBUG [org.jasig.cas.persondir.LdapPersonAttributeDao] - <Generated query builder '[org.ldaptive.SearchFilter@-1899072907::filter=uid={0}, parameters={0=sarts}]' from query Map {username=[sarts]}.> 2014-04-22 11:51:48,077 DEBUG [org.jasig.cas.persondir.LdapPersonAttributeDao] - <Converted ldap DN entry [uid=sarts,ou=People,o=esa.nl] to attribute map {<snip>}> 2014-04-22 11:51:48,078 DEBUG [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <org.jasig.cas.authentication.principal.PersonDirectoryPrincipalResolver@51d83fd7 resolved sarts from sarts+password> 2014-04-22 11:51:48,078 INFO [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <Authenticated sarts with credentials [sarts+password].> 2014-04-22 11:51:48,078 DEBUG [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <Attribute map for sarts: {Name=Stephan Arts, [email protected]}> 2014-04-22 11:51:48,078 INFO [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN 
=============================================================
WHO: audit:unknown
WHAT: supplied credentials: [sarts+password]
ACTION: AUTHENTICATION_SUCCESS
APPLICATION: CAS
WHEN: Tue Apr 22 11:51:48 CEST 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================

>
2014-04-22 11:51:48,078 DEBUG [org.jasig.cas.ticket.registry.EhCacheTicketRegistry] - <Adding ticket granting ticket TGT-5-tNnPYhRnZBxQHTb2qmrpQgYpnasnO3muKGeMtkpO2UFKcpKtid-cas01.example.org to the cache org.jasig.cas.ticket.TicketGrantingTicket> 2014-04-22 11:51:48,079 INFO [com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN 
=============================================================
WHO: audit:unknown
WHAT: TGT-5-tNnPYhRnZBxQHTb2qmrpQgYpnasnO3muKGeMtkpO2UFKcpKtid-cas01.example.org 
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Tue Apr 22 11:51:48 CEST 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================

>
2014-04-22 11:51:48,079 DEBUG [org.jasig.cas.web.support.CookieRetrievingCookieGenerator] - <Removed cookie with name [CASPRIVACY]> 2014-04-22 11:51:48,080 DEBUG [org.jasig.cas.web.support.CasArgumentExtractor] - <Extractor generated service for: http://cosmos.esa.int> 2014-04-22 11:51:48,081 DEBUG [org.jasig.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages_en] - neither plain properties nor XML> 2014-04-22 11:51:48,081 DEBUG [org.jasig.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages] - neither plain properties nor XML> 2014-04-22 11:51:48,082 DEBUG [org.jasig.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:messages_en] - neither plain properties nor XML> 2014-04-22 11:51:48,082 DEBUG [org.jasig.cas.web.view.CasReloadableMessageBundle] - <Re-caching properties for filename [classpath:messages] - file hasn't been modified> 2014-04-22 11:53:21,227 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Reloading registered services.> 

It doesn't appear to show anything related to servicetickets.

Regards,

Stephan

On 22/04/14 11:33, Misagh Moayyed wrote:

Turn on DEBUG levels in the configuration for org.jasig.cas first.
What is the service you're trying to access? Is that indicated to CAS when 
you login?


-----Original Message-----
From: Stephan Arts [mailto:[email protected]]
Sent: Tuesday, April 22, 2014 1:49 AM
To: [email protected]
Subject: [cas-user] CAS 4.0.0-RC4 not generating service tickets


Hi,
I am having a peculiar problem on my test machine running cas 4.0.0-RC4 

For some reason it is not generating ServiceTickets when I log in.
This behaviour is identical when I run my overlay on cas 4.0.0-RC3, and 
when

I use the default in-memory ticketregistry, or the ehcache

ticketregistry.

The latter makes it easier for me to identify that indeed no ticket is
created.

  From the logs:

2014-04-22 10:35:38,227 INFO
[org.jasig.cas.web.flow.InitialFlowSetupAction] - <Setting path for

cookies

to: /cas/>
2014-04-22 10:35:47,053 INFO
[org.jasig.cas.authentication.PolicyBasedAuthenticationManager] -
<LdapAuthenticationHandler successfully authenticated sarts+password>
2014-04-22 10:35:47,077 INFO
[org.jasig.cas.authentication.PolicyBasedAuthenticationManager] -
<Authenticated sarts with credentials [sarts+password].>
2014-04-22 10:35:47,084 INFO
[com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] -

<Audit

trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: supplied credentials: [sarts+password]
ACTION: AUTHENTICATION_SUCCESS
APPLICATION: CAS
WHEN: Tue Apr 22 10:35:47 CEST 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================

  >
2014-04-22 10:35:47,093 INFO
[com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager] -

<Audit

trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT:
TGT-1-ZHbVIbfmsfzocbqxacomf2zTcyVa4boAP44kWxBeKqkuw0ePnR-cas01.example.org 
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Tue Apr 22 10:35:47 CEST 2014
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================

  >
2014-04-22 10:37:28,579 INFO
[org.jasig.cas.services.DefaultServicesManagerImpl] - <Reloading

registered

services.>
2014-04-22 10:37:28,580 INFO
[org.jasig.cas.services.DefaultServicesManagerImpl] - <Loaded 1

services.>

The TGT is in the eh-cache disk store (I can see it in the file).

Since I can reproduce this issue with 2 RC's, I am fairly positive I

have

broken something in my overlay. However, I am a bit puzzled on the

debugging

side of things.
I know the information I'm giving is sparse, I'm sorry about that. I am 
just

not sure where to start debugging now.

How would you propose I continue investigating this issue?

Regards,

Stephan

--
You are currently subscribed to [email protected] as:
[email protected] To unsubscribe, change settings or access archives, 
see

http://www.ja-sig.org/wiki/display/JSG/cas-user









--
You are currently subscribed to [email protected] as: 
[email protected]
To unsubscribe, change settings or access archives, see 
http://www.ja-sig.org/wiki/display/JSG/cas-user

Reply via email to