Idp 3 could not open connection to MySql

Wed Oct 28 13:49:01 UTC 2020

Hi all,
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.
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:

> From idp-warn.log:
2020-10-19 12:42:05,728 - WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper:144] - SQL Error: 0, SQLState: null
2020-10-19  12:42:05,728 - ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper:146] - Cannot get a connection, pool error Timeout waiting for idle object
2020-10-19  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'
javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection
        at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)
Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:116)
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1174)
2020-10-19  12:42:05,738 - ERROR [org.opensaml.storage.ReplayCache:144] - Exception reading/writing to storage service, returning failure
java.io.IOException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection
        at org.opensaml.storage.impl.JPAStorageService.readImpl(JPAStorageService.java:342)
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Could not open connection
        at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)
Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:116)
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1174)
2020-10-19  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'
2020-10-19  12:42:05,739 - WARN [net.shibboleth.idp.profile.impl.WebFlowMessageHandlerAdaptor:202] - Profile Action WebFlowMessageHandlerAdaptor: Exception handling message
org.opensaml.messaging.handler.MessageHandlerException: Rejecting replayed message ID '_4aa022d38c99fdd0b63f61768ed36762' from issuer https://apache-frontend.test/shibboleth
        at org.opensaml.saml.common.binding.security.impl.MessageReplaySecurityHandler.doInvoke(MessageReplaySecurityHandler.java:157)
2020-10-19  12:42:05,740 - WARN [org.opensaml.profile.action.impl.LogEvent:105] - A non-proceed event occurred while processing the request: MessageReplay

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...
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.
I tried doing many connection to MySql with a script monitoring the Idp status and sometimes is stops and sometimes don't.

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

> From global.xml:
<bean id="MyShibDatasource" class="org.apache.commons.dbcp.BasicDataSource"
      p:driverClassName="com.mysql.jdbc.Driver"
      p:url="jdbc:mysql://localhost:3306/shib?autoReconnect=true"
      p:username="username"
      p:password="password"
      p:maxActive="150"
      p:maxIdle="5"
      p:maxWait="15000"
      p:testOnBorrow="true"
      p:validationQuery="select 1"
      p:validationQueryTimeout="5" />

that now is 150 from 10 before.
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.
The last thing that i saw is many error like this one:

> From idp-warn.log:
2020-10-19  05:08:19,784 - ERROR [org.opensaml.storage.impl.JPAStorageService:348] - Error committing transaction
javax.persistence.RollbackException: Error while committing the transaction
        at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:94)
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
        at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)

where the username is just the same except some upper/lowercase letters. This can be the source of my problem?

Where i am wrong? I am missing something??
Thank you for any help and sorry for my bad english
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20201028/6b845e60/attachment.htm>