Misagh,
Thank you for the quick response!
I gave that a shot but unfortunately I am still seeing the same behavior.
I simplified the configuration by reverting to the baseline 4.2.4-SNAPSHOT
deployerConfigContext.xml with a single modification:
<!-- <alias name="defaultTicketRegistry" alias="ticketRegistry" /> -->
<alias name="jpaTicketRegistry" alias="ticketRegistry" />
After a successful authentication the application appears to hang and the
following INSERT into the TGT table never completes.
I increased the logging level on the MySQL database and reviewed the
transactions. Interestingly, I don’t see the INSERT in the MySQL logs.
2016-06-28 07:28:32,519 DEBUG
[org.hibernate.engine.transaction.internal.TransactionImpl] - <begin>
2016-06-28 07:28:32,576 DEBUG
[org.hibernate.event.internal.AbstractSaveEventListener] - <Generated
identifier:
TGT-1-m3uVAIDLCrNx3kALGEi1tCoEeB0P2JwGOfFpw43oLEgfKyhb6h-cas01.example.org,
using strategy: org.hibernate.id.Assigned>
2016-06-28 07:28:32,674 INFO
[org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail
record BEGIN
=============================================================
WHO: audit:unknown
WHAT:
TGT-**********************************************LEgfKyhb6h-cas01.example.org
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Tue Jun 28 07:28:32 CDT 2016
CLIENT IP ADDRESS: 10.213.88.36
SERVER IP ADDRESS: 10.186.86.6
=============================================================
>
2016-06-28 07:28:32,675 DEBUG
[org.hibernate.engine.transaction.internal.TransactionImpl] - <committing>
2016-06-28 07:28:32,676 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Processing
flush-time cascades>
2016-06-28 07:28:32,677 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Dirty checking
collections>
2016-06-28 07:28:32,685 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Flushed: 1
insertions, 0 updates, 0 deletions to 1 objects>
2016-06-28 07:28:32,685 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Flushed: 0
(re)creations, 0 updates, 0 removals to 0 collections>
2016-06-28 07:28:32,688 DEBUG [org.hibernate.internal.util.EntityPrinter] -
<Listing entities:>
2016-06-28 07:28:32,689 DEBUG [org.hibernate.internal.util.EntityPrinter] -
<org.jasig.cas.ticket.TicketGrantingTicketImpl{lastTimeUsed=1467116912575,
previousLastTimeUsed=0, proxiedBy=null, supplementalAuthentications=[],
expired=false, creationTime=1467116912575, countOfUses=0,
id=TGT-1-m3uVAIDLCrNx3kALGEi1tCoEeB0P2JwGOfFpw43oLEgfKyhb6h-cas01.example.org,
expirationPolicy=org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy@60ea79d1,
services={}, ticketGrantingTicket=null,
authentication=org.jasig.cas.authentication.ImmutableAuthentication@cf5621ae}>
Hibernate: insert into TICKETGRANTINGTICKET (NUMBER_OF_TIMES_USED,
CREATION_TIME, EXPIRATION_POLICY, LAST_TIME_USED, PREVIOUS_LAST_TIME_USED,
ticketGrantingTicket_ID, AUTHENTICATION, EXPIRED, PROXIED_BY,
SERVICES_GRANTED_ACCESS_TO, SUPPLEMENTAL_AUTHENTICATIONS, TYPE, ID) values (?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, 'TGT', ?)
2016-06-28 07:28:32,726 DEBUG [org.hibernate.SQL] - <insert into
TICKETGRANTINGTICKET (NUMBER_OF_TIMES_USED, CREATION_TIME, EXPIRATION_POLICY,
LAST_TIME_USED, PREVIOUS_LAST_TIME_USED, ticketGrantingTicket_ID,
AUTHENTICATION, EXPIRED, PROXIED_BY, SERVICES_GRANTED_ACCESS_TO,
SUPPLEMENTAL_AUTHENTICATIONS, TYPE, ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, 'TGT', ?)>
2016-06-28 07:28:45,129 DEBUG [org.quartz.core.QuartzSchedulerThread] - <batch
acquisition of 1 triggers>
2016-06-28 07:28:50,464 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<Refurbishing idle resources - Tue Jun 28 07:28:50 CDT 2016
[com.mchange.v2.resourcepool.BasicResourcePool@4673a74]>
2016-06-28 07:28:50,465 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@8dcec67] on IDLE CHECK.>
2016-06-28 07:28:50,465 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@378e94cf] on IDLE CHECK.>
2016-06-28 07:28:50,465 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@100f9122] on IDLE CHECK.>
2016-06-28 07:28:50,467 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@100f9122] on IDLE CHECK has
SUCCEEDED.>
2016-06-28 07:28:50,467 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@20182d8a] on IDLE CHECK.>
2016-06-28 07:28:50,468 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@8dcec67] on IDLE CHECK has
SUCCEEDED.>
2016-06-28 07:28:50,468 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@30391200] on IDLE CHECK.>
2016-06-28 07:28:50,469 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@20182d8a] on IDLE CHECK has
SUCCEEDED.>
2016-06-28 07:28:50,469 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@30391200] on IDLE CHECK has
SUCCEEDED.>
2016-06-28 07:28:50,471 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@378e94cf] on IDLE CHECK has
SUCCEEDED.>
2016-06-28 07:29:09,730 DEBUG [org.quartz.core.QuartzSchedulerThread] - <batch
acquisition of 0 triggers>
2016-06-28 07:29:09,730 DEBUG [org.quartz.core.JobRunShell] - <Calling execute
on job DEFAULT.DefaultServicesManagerImpl361f5f80-a0ee-4777-bbc6-070165fd23d7>
2016-06-28 07:29:09,730 INFO
[org.jasig.cas.services.DefaultServicesManagerImpl] - <Reloading registered
services.>
2016-06-28 07:29:09,735 INFO
[org.jasig.cas.services.DefaultServicesManagerImpl] - <Loaded 2 services from
JsonServiceRegistryDao.>
I’m starting to wonder if the issue could be the MySQL release. We are running
5.7 but using the MySQL 5.7 InnoDB dialect for hibernate resulted in an
exception during table creation.
The database initializes correctly using the MySQL 5 InnoDB dialect and the
health check seems to work but obviously the INSERT isn’t working.
Thanks,
Tom O’Neill
From: [email protected] [mailto:[email protected]] On Behalf Of Misagh
Moayyed
Sent: Monday, June 27, 2016 5:30 PM
To: [email protected]
Subject: RE: [cas-user] CAS 4.2.2 jpaTicketRegistry Issues
Point your overlay to 4.2.4-SNAPSHOT and try again please. (make sure you force
an update with –U)
From: [email protected]<mailto:[email protected]>
[mailto:[email protected]] On Behalf Of Tom O'Neill
Sent: Monday, June 27, 2016 12:05 PM
To: [email protected]<mailto:[email protected]>
Subject: [cas-user] CAS 4.2.2 jpaTicketRegistry Issues
Hi All,
Hopefully I’m just missing something simple…I appreciate any and all insight.
I’ve worked on 3.5.x extensively and 4.0.x briefly but 4.2.2 is giving me some
trouble.
I am working on a 4.2.2 CAS build using the Maven overlay method and I’d like
to use LDAP and JPA support.
I added LDAP support, JPA Ticket Registry support and MySQL 5.1.39 to my
pom.xml:
<dependencies>
<dependency>
<groupId>org.jasig.cas</groupId>
<artifactId>cas-server-webapp</artifactId>
<version>${cas.version}</version>
<type>war</type>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>org.jasig.cas</groupId>
<artifactId>cas-server-support-ldap</artifactId>
<version>${cas.version}</version>
</dependency>
<dependency>
<groupId>org.jasig.cas</groupId>
<artifactId>cas-server-support-jpa-ticket-registry</artifactId>
<version>${cas.version}</version>
</dependency>
<dependency>
<groupId>mysql</groupId>
<artifactId>mysql-connector-java</artifactId>
<version>5.1.39</version>
</dependency>
</dependencies>
After getting LDAP working with the default ticket registry, I then updated
src/main/webapp/WEB-INF/deployerConfigContext.xml as follows:
<!-- TONeill/JPA Ticket registry -->
<!-- <alias name="defaultTicketRegistry" alias="ticketRegistry" /> -->
<alias name="jpaTicketRegistry" alias="ticketRegistry" />
I also added the ticket registry database properties to my cas.properties file.
I am using a 5.7 MySQL InnoDB so I have the following dialect set:
org.hibernate.dialect.MySQL5InnoDBDialect
After authentication succeeds I see hibernate indicate that it is going to
attempt an insert into the ticketgrantingticket table but the insert never
seems to complete.
2016-06-27 13:34:51,614 DEBUG
[org.hibernate.engine.transaction.internal.TransactionImpl] - <begin>
2016-06-27 13:34:51,623 DEBUG
[org.hibernate.event.internal.AbstractSaveEventListener] - <Generated
identifier: TGT-1-1Pzdcw6T0gSjt4SQwa2q5CgI2x373ayd72CHMcjK2wfet0bAv2-auth1test,
using strategy: org.hibernate.id.Assigned>
2016-06-27 13:34:51,715 INFO
[org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail
record BEGIN
=============================================================
WHO: audit:unknown
WHAT: TGT-**********************************************2wfet0bAv2-auth1test
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Mon Jun 27 13:34:51 CDT 2016
CLIENT IP ADDRESS: 10.213.88.21
SERVER IP ADDRESS: 10.186.86.6
=============================================================
>
2016-06-27 13:34:51,716 DEBUG
[org.hibernate.engine.transaction.internal.TransactionImpl] - <committing>
2016-06-27 13:34:51,716 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Processing
flush-time cascades>
2016-06-27 13:34:51,717 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Dirty checking
collections>
2016-06-27 13:34:51,723 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Flushed: 1
insertions, 0 updates, 0 deletions to 1 objects>
2016-06-27 13:34:51,723 DEBUG
[org.hibernate.event.internal.AbstractFlushingEventListener] - <Flushed: 0
(re)creations, 0 updates, 0 removals to 0 collections>
2016-06-27 13:34:51,723 DEBUG [org.hibernate.internal.util.EntityPrinter] -
<Listing entities:>
2016-06-27 13:34:51,724 DEBUG [org.hibernate.internal.util.EntityPrinter] -
<org.jasig.cas.ticket.TicketGrantingTicketImpl{lastTimeUsed=1467052491621,
previousLastTimeUsed=0, proxiedBy=null, supplementalAuthentications=[],
expired=false, creationTime=1467052491621, countOfUses=0,
id=TGT-1-1Pzdcw6T0gSjt4SQwa2q5CgI2x373ayd72CHMcjK2wfet0bAv2-auth1test,
expirationPolicy=org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy@42f8ab07<mailto:expirationPolicy=org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy@42f8ab07>,
services={}, ticketGrantingTicket=null,
authentication=org.jasig.cas.authentication.ImmutableAuthentication@c0763239<mailto:authentication=org.jasig.cas.authentication.ImmutableAuthentication@c0763239>}>
Hibernate: insert into TICKETGRANTINGTICKET (NUMBER_OF_TIMES_USED,
CREATION_TIME, EXPIRATION_POLICY, LAST_TIME_USED, PREVIOUS_LAST_TIME_USED,
ticketGrantingTicket_ID, AUTHENTICATION, EXPIRED, PROXIED_BY,
SERVICES_GRANTED_ACCESS_TO, SUPPLEMENTAL_AUTHENTICATIONS, TYPE, ID) values (?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?, 'TGT', ?)
2016-06-27 13:34:51,730 DEBUG [org.hibernate.SQL] - <insert into
TICKETGRANTINGTICKET (NUMBER_OF_TIMES_USED, CREATION_TIME, EXPIRATION_POLICY,
LAST_TIME_USED, PREVIOUS_LAST_TIME_USED, ticketGrantingTicket_ID,
AUTHENTICATION, EXPIRED, PROXIED_BY, SERVICES_GRANTED_ACCESS_TO,
SUPPLEMENTAL_AUTHENTICATIONS, TYPE, ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?,
?, 'TGT', ?)>
2016-06-27 13:35:01,612 DEBUG [com.mchange.v2.resourcepool.BasicResourcePool] -
<Refurbishing idle resources - Mon Jun 27 13:35:01 CDT 2016
[com.mchange.v2.resourcepool.BasicResourcePool@156eeecf]>
2016-06-27 13:35:01,612 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@7eb9ca3c] on IDLE CHECK.>
2016-06-27 13:35:01,613 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@b2132c4] on IDLE CHECK.>
2016-06-27 13:35:01,613 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@3ee0eb3d] on IDLE CHECK.>
2016-06-27 13:35:01,616 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@b2132c4] on IDLE CHECK has
SUCCEEDED.>
2016-06-27 13:35:01,616 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@cd8fa76] on IDLE CHECK.>
2016-06-27 13:35:01,616 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@3ee0eb3d] on IDLE CHECK has
SUCCEEDED.>
2016-06-27 13:35:01,616 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Testing PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@54b032c8] on IDLE CHECK.>
2016-06-27 13:35:01,616 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@7eb9ca3c] on IDLE CHECK has
SUCCEEDED.>
2016-06-27 13:35:01,617 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@cd8fa76] on IDLE CHECK has
SUCCEEDED.>
2016-06-27 13:35:01,617 DEBUG
[com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool] - <Test of PooledConnection
[com.mchange.v2.c3p0.impl.NewPooledConnection@54b032c8] on IDLE CHECK has
SUCCEEDED.>
Thanks,
Tom O’Neill
--
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]<mailto:[email protected]>.
To post to this group, send email to
[email protected]<mailto:[email protected]>.
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/BY1PR0201MB099948E01CE07680743753A6CB210%40BY1PR0201MB0999.namprd02.prod.outlook.com<https://groups.google.com/a/apereo.org/d/msgid/cas-user/BY1PR0201MB099948E01CE07680743753A6CB210%40BY1PR0201MB0999.namprd02.prod.outlook.com?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 [email protected]<mailto:[email protected]>.
To post to this group, send email to
[email protected]<mailto:[email protected]>.
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/002901d1d0bb%241e69ffa0%245b3dfee0%24%40unicon.net<https://groups.google.com/a/apereo.org/d/msgid/cas-user/002901d1d0bb%241e69ffa0%245b3dfee0%24%40unicon.net?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 [email protected].
To post to this group, send email to [email protected].
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/BY1PR0201MB099973FCFB22CE324D1AB33DCB220%40BY1PR0201MB0999.namprd02.prod.outlook.com.
For more options, visit https://groups.google.com/a/apereo.org/d/optout.
