<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=iso-8859-1">
<style type="text/css" style="display:none;"> P {margin-top:0;margin-bottom:0;} </style>
</head>
<body dir="ltr">
<div style="font-family: Calibri, Helvetica, sans-serif; font-size: 12pt; color: rgb(0, 0, 0);">
</div>
Hi all,
<div>I had a problem with my setup where i have a Tomcat 8.5 with Idp 3.3 and i store the consensus in a MySql database. It was working perfectly since last year when i started the service.</div>
<div>In the last couple weeks, sometimes the idp stop working. It's gone exactly one year from when the first user release the consensus and while the idp was not responding in the log file appear this error:</div>
<div> </div>
<div>> <i><u>From idp-warn.log</u></i>:</div>
<div><i>2020-10-19 12:42:05,728 - WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper:144] - SQL Error: 0, SQLState: null</i></div>
<div><i>2020-10-<i style="color:rgb(0, 0, 0);font-size:14px;background-color:rgb(255, 255, 255)">19<span> </span></i> 12:42:05,728 - ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper:146] - Cannot get a connection, pool error Timeout waiting for idle
object</i></div>
<div><i>2020-10-<i style="color:rgb(0, 0, 0);font-size:14px;background-color:rgb(255, 255, 255)">19<span> </span></i> 12:42:05,736 - ERROR [org.opensaml.storage.impl.JPAStorageService:334] - Error reading record '_4aa022d38c99fdd0b63f61768ed36762' in context
'org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler'</i></div>
<div><i>javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection</i></div>
<div><i> at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)</i></div>
<div><i>Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection</i></div>
<div><i> at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)</i></div>
<div><i>Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object</i></div>
<div><i> at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:116)</i></div>
<div><i>Caused by: java.util.NoSuchElementException: Timeout waiting for idle object</i></div>
<div><i> at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1174)</i></div>
<div><i>2020-10-<i style="color:rgb(0, 0, 0);font-size:14px;background-color:rgb(255, 255, 255)">19<span> </span></i> 12:42:05,738 - ERROR [org.opensaml.storage.ReplayCache:144] - Exception reading/writing to storage service, returning failure</i></div>
<div><i>java.io.IOException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection</i></div>
<div><i> at org.opensaml.storage.impl.JPAStorageService.readImpl(JPAStorageService.java:342)</i></div>
<div><i>Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection</i></div>
<div><i> at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)</i></div>
<div><i>Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection</i></div>
<div><i> at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)</i></div>
<div><i>Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object</i></div>
<div><i> at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:116)</i></div>
<div><i>Caused by: java.util.NoSuchElementException: Timeout waiting for idle object</i></div>
<div><i> at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1174)</i></div>
<div><i>2020-10-<i style="color:rgb(0, 0, 0);font-size:14px;background-color:rgb(255, 255, 255)">19<span> </span></i> 12:42:05,739 - WARN [org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler:156] - Message Handler: Replay detected of
message '_4aa022d38c99fdd0b63f61768ed36762' from issuer 'https://apache-frontend.test/shibboleth'</i></div>
<div><i>2020-10-<i style="color:rgb(0, 0, 0);font-size:14px;background-color:rgb(255, 255, 255)">19<span> </span></i> 12:42:05,739 - WARN [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:202] - Profile Action WebFlowMessageHandlerAdaptor: Exception
handling message</i></div>
<div><i>org.opensaml.messaging.handler.MessageHandlerException: Rejecting replayed message ID '_4aa022d38c99fdd0b63f61768ed36762' from issuer https://apache-frontend.test/shibboleth</i></div>
<div><i> at org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler.doInvoke(MessageReplaySecurityHandler.java:157)</i></div>
<div><i>2020-10-<i style="color:rgb(0, 0, 0);font-size:14px;background-color:rgb(255, 255, 255)">19<span> </span></i> 12:42:05,740 - WARN [org.opensaml.profile.action.impl.LogEvent:105] - A non-proceed event occurred while processing the request: MessageReplay</i></div>
<div><br>
</div>
<div><br>
</div>
<div>It seems that Tomcat/Idp cannot open a new connection to MySql but the problem is that MySql is working fine: i can connect from command line and also from the manager and noone is reporting an error...
</div>
<div>The strangest thing is that is not happening regularly. Something it happens with a huge network traffic and sometimes in the middle of the night when the traffic is nearly zero.
</div>
<div>I tried doing many connection to MySql with a script monitoring the Idp status and sometimes is stops and sometimes don't.</div>
<div><br>
</div>
<div>The only thing that i see producing some results is changing the connection timeout in MySql configuration (60 seconds) and the number of connections in global.xml
</div>
<div><br>
</div>
<div>> <u><i>From global.xml</i></u>: </div>
<div><i><bean id="MyShibDatasource" class="org.apache.commons.dbcp.BasicDataSource"</i></div>
<div><i> p:driverClassName="com.mysql.jdbc.Driver"</i></div>
<div><i> p:url="jdbc:mysql://localhost:3306/shib?autoReconnect=true"</i></div>
<div><i> p:username="username"</i></div>
<div><i> p:password="password"</i></div>
<div><i> p:maxActive="150"</i></div>
<div><i> p:maxIdle="5"</i></div>
<div><i> p:maxWait="15000"</i></div>
<div><i> p:testOnBorrow="true"</i></div>
<div><i> p:validationQuery="select 1"</i></div>
<div><i> p:validationQueryTimeout="5" /></i></div>
<div><br>
</div>
<div>that now is 150 from 10 before.</div>
<div>One more thing that i saw is that expired the first year there are many 'DEL' operation saved on MySql and i don't know if that can be related.</div>
<div>The last thing that i saw is many error like this one:</div>
<div><br>
</div>
<div>> <i><u>From idp-warn.log:</u></i></div>
<div><i>2020-10-<i style="color:rgb(0, 0, 0);font-size:14px;background-color:rgb(255, 255, 255)">19<span> </span></i> 05:08:19,784 - ERROR [org.opensaml.storage.impl.JPAStorageService:348] - Error committing transaction</i>
<div><i>javax.persistence.RollbackException: Error while committing the transaction</i></div>
<div><i> at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:94)</i></div>
<div><i>Caused by: javax.persistence.PersistenceException: org.hibernate.HibernateException: identifier of an instance of org.opensaml.storage.impl.JPAStorageRecord was altered from intercept/attribute-release:pinco.pallino to intercept/attribute-release:Pinco.Pallino</i></div>
<div><i> at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)</i></div>
</div>
<div><br>
</div>
<div>where the username is just the same except some upper/lowercase letters. This can be the source of my problem?</div>
<div><br>
</div>
<div>Where i am wrong? I am missing something??</div>
Thank you for any help and sorry for my bad english
<div style="font-family: Calibri, Helvetica, sans-serif; font-size: 12pt; color: rgb(0, 0, 0);">
</div>
</body>
</html>