Hi again,

It's been about a month and have regularly screened the JVM memory - it 
looks fine since the memory bumps, running CAS v4.2.4.

However, the server fell over again (using the JPA ticket registry), with 
the same behavior: upon entering correct credentials, a user is redirected 
back to the login page rather than logging in. I'm not sure where to go 
from here to ensure a more reliable service, and would like to hear your 
input.

While digging, I've found three types of exceptions in the logs:

1: deadlocks
SEVERE: Servlet.service() for servlet [cas] in context with path [/cas] 
threw exception [Request processing failed; nested exception is 
org.springframework.webflow.execution.ActionExecutionException: Exception 
thrown executing 
org.jasig.cas.web.flow.GenerateServiceTicketAction@4805bd13 in state 
'generateServiceTicket' of flow 'login' -- action execution attributes were 
'map[[empty]]'] with root cause
com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock 
found when trying to get lock; try restarting transaction                   
                                                  [265/9592]
        at sun.reflect.GeneratedConstructorAccessor127.newInstance(Unknown 
Source)
        at 
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)
        at com.mysql.jdbc.Util.getInstance(Util.java:387)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:946)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3878)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3814)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
        at 
com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
        at 
com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2073)
        at 
com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1751)
        at 
com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1257)
        at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:959)
        at 
com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2544)

2: badly formatted keys
SEVERE: Servlet.service() for servlet [cas] in context with path [/cas] 
threw exception [Request processing failed; nested exception is 
org.springframework.webflow.execution.repository.BadlyFormattedFlowExecution
KeyException: Badly formatted flow execution key '', the expected format is 
'<uuid>_<base64-encoded-flow-state>'] with root cause
org.springframework.webflow.execution.repository.BadlyFormattedFlowExecutionKeyException:
 
Badly formatted flow execution key '', the expected format is 
'<uuid>_<base64-encoded-flow-state>'
        at 
org.jasig.spring.webflow.plugin.ClientFlowExecutionKey.parse(ClientFlowExecutionKey.java:102)
        at 
org.jasig.spring.webflow.plugin.ClientFlowExecutionRepository.parseFlowExecutionKey(ClientFlowExecutionRepository.java:74)
        at 
org.springframework.webflow.executor.FlowExecutorImpl.resumeExecution(FlowExecutorImpl.java:164)
        at 
org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:228)
        at 
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959)
        at 
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893)
        at 
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
        at 
org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:646)
        at 
org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at 
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
        at 
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at 
org.apereo.cas.security.ResponseHeadersEnforcementFilter.doFilter(ResponseHeadersEnforcementFilter.java:238)
        at 
org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)

3: constraint violations
Sep 22, 2016 9:48:20 AM org.apache.catalina.core.StandardWrapperValve invoke
SEVERE: Servlet.service() for servlet [cas] in context with path [/cas] 
threw exception [Request processing failed; nested exception is 
org.springframework.webflow.execution.ActionExecutionException: Exception th
rown executing org.jasig.cas.web.flow.GenerateServiceTicketAction@4805bd13 
in state 'generateServiceTicket' of flow 'login' -- action execution 
attributes were 'map[[empty]]'] with root cause
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: 
Cannot add or update a child row: a foreign key constraint fails 
(`cas`.`SERVICETICKET`, CONSTRAINT `FK(TGTID)` FOREIG
N KEY (`ticketGrantingTicket_ID`) REFERENCES `TICKETGRANTINGTICKET` (`ID`))
        at sun.reflect.GeneratedConstructorAccessor131.newInstance(Unknown 
Source)
        at 
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)
        at com.mysql.jdbc.Util.getInstance(Util.java:387)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:932)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3878)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3814)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
        at 
com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
        at 
com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2073)
        at 
com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1751)
        at 
com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1257)
        at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:959)
        at 
com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2544)
        at 
org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:110)
        at 
org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:97)
        at 
org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:147)
        at 
org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:214)
        at 
org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:470)

I'm hoping something is just mis-configured in my config, and wondering if 
the exceptions here give any clue as to what they might be. Exceptions 1 
and 3 seem like something is strange with my JPA registry. I'm using C3P0 
as my jdbc connection pool ('com.mchange:c3p0:0.9.5.2'), and 
mysql-connector ('mysql:mysql-connector-java:5.1.38').

Thanks,
Jeff

On Thursday, August 25, 2016 at 10:56:42 PM UTC-7, Misagh Moayyed wrote:
>
>
> Ah, JVM stats. Thanks for that tip: I really wasn't looking at my memory 
> closely enough, and I still had a -Xmx128m set (tomcat7 default in ubuntu). 
> I bumped it to 1g (actually this time, confirmed via /status this time) so 
> I'm hoping this helps resolve.
>
> Ah! That should do it. I am surprised you were able to last a few months 
> with that setting. My preference is somewhere between 2g and 4g. 
>
>
> /status wasn't working for localhost by default, but this was due to IPv6 
> on my end. Would you be open to changing the 
> default cas.securityContext.adminpages.ip=(127\.0\.0\.1|0:0:0:0:0:0:0:1) to 
> support IPv6 localhost?
>
> No problem. File an issue please.
>
>
> I'm planning on throwing on a lot more memory monitoring near future. I'm 
> assuming this would be a very likely root cause for these sorts off issues 
> - sorry I didn't catch that earlier.
>
> Hoping this is the ticket (hurr hurr) - I'll let you know if anything else 
> interesting comes up, but I really appreciate your support!
>
> No worries. All I did was to echo back what you already knew. 
>
>

-- 
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/bf289bbe-341e-481e-b2a5-6eda5c5aac1c%40apereo.org.
For more options, visit https://groups.google.com/a/apereo.org/d/optout.

Reply via email to