Shibboleth and database connection leak

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

Shibboleth and database connection leak

Tobias Galéus
We are having problems with our Shibboleth IDP 3.3.3 losing database
connections. While I do not think this is a bug in Shibboleth I guess it
might be a configuration error.

We are currently using HikariCP, but we've also tried commons dbcp with the
same result. When enabling logging and leak detection in Hikari it reports a
connection leak after about 5 minutes:

10:49:28.960 [HikariPool-1 housekeeper] Connection leak detection triggered
for com.mysql.jdbc.JDBC4Connection@5f233c05 on thread qtp721748895-11, stack
trace follows
java.lang.Exception: Apparent connection leak detected
(Full stack trace available here: https://pastebin.com/LTx9x2X2 )

Of the 4 connections that I've configured Hikari to use, only 1 remains
after a few hours. While this last connection seem to be working fine, it
has happened that this connection also dies and the no more connection
attempts are made to the DB and Shibboleth (of course) stops functioning.

Does anyone have an idea on how to resolve this? I'm quite clueless here.

Pasting some related configuration from our installation here:

From global.xml:

    <bean id="shibboleth.JPAStorageService"
class="org.opensaml.storage.impl.JPAStorageService"
       p:cleanupInterval="%{idp.storage.cleanupInterval:PT10M}"
c:factory-ref="shibboleth.JPAStorageService.EntityManagerFactory" />
    <bean id="shibboleth.JPAStorageService.EntityManagerFactory"
class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
    <property name="persistenceUnitName" value="storageservice" />
    <property name="packagesToScan" value="org.opensaml.storage.impl" />
    <property name="dataSource"
ref="shibboleth.JPAStorageService.DataSource" />
    <property name="jpaVendorAdapter"
ref="shibboleth.JPAStorageService.JPAVendorAdapter" />
    <property name="jpaDialect">
        <bean class="org.springframework.orm.jpa.vendor.HibernateJpaDialect"
/>
    </property>
    </bean>
    <bean id="shibboleth.JPAStorageService.JPAVendorAdapter"
class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter">
    <property name="database" value="MYSQL" />
    </bean>

    <bean id="shibboleth.JPAStorageService.DataSource"
    class="com.zaxxer.hikari.HikariDataSource" destroy-method="close"
lazy-init="true"
    p:driverClassName="com.mysql.jdbc.Driver"
   
p:jdbcUrl="jdbc:mysql://127.0.0.1:3306/shibboleth?cachePrepStmts=true&amp;prepStmtCacheSize=250&amp;prepStmtCacheSqlLimit=2048&amp;cachePrepStmts=true&amp;useServerPrepStmts=true"
    p:username="USERNAME"
    p:password="P@SSWORD"
    p:autoCommit="false"
    p:transactionIsolation="8"
    p:leakDetectionThreshold="300000"
    p:maximumPoolSize="4"
    p:maxLifetime="28000000"
    />

mysql> SHOW VARIABLES LIKE "wait_timeout%";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout  | 28800 |
+---------------+-------+
1 row in set (0.00 sec)

From idp.properties:
idp.session.StorageService = shibboleth.JPAStorageService
idp.consent.StorageService = shibboleth.JPAStorageService
idp.replayCache.StorageService = shibboleth.JPAStorageService
idp.artifact.StorageService = shibboleth.JPAStorageService
idp.cas.StorageService=shibboleth.JPAStorageService

/opt/shibboleth-idp/edit-webapp/WEB-INF/lib/
-rw-r--r--. 1 jetty jetty 968670 Jun 15  2016
mysql-connector-java-5.1.35-bin.jar
-rw-r--r--. 1 jetty jetty 174167 Jun 15  2016 commons-dbcp2-2.1.1.jar
-rw-r--r--. 1 jetty jetty 111969 Jun 15  2016 commons-pool2-2.4.2.jar
-rw-r--r--. 1 jetty jetty 143188 May  3 12:14 HikariCP-3.1.0.jar





--
Sent from: http://shibboleth.1660669.n2.nabble.com/Shibboleth-Users-f1660767.html
--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]
Reply | Threaded
Open this post in threaded view
|

Re: Shibboleth and database connection leak

Daniel Fisher-2
On Thu, Jun 28, 2018 at 8:33 AM Tobias Galéus <[hidden email]> wrote:
    <bean id="shibboleth.JPAStorageService.JPAVendorAdapter"
class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter">
    <property name="database" value="MYSQL" />
    </bean>

    <bean id="shibboleth.JPAStorageService.DataSource"
    class="com.zaxxer.hikari.HikariDataSource" destroy-method="close"
lazy-init="true"
    p:driverClassName="com.mysql.jdbc.Driver"

p:jdbcUrl="jdbc:mysql://127.0.0.1:3306/shibboleth?cachePrepStmts=true&amp;prepStmtCacheSize=250&amp;prepStmtCacheSqlLimit=2048&amp;cachePrepStmts=true&amp;useServerPrepStmts=true"
    p:username="USERNAME"
    p:password="P@SSWORD"
    p:autoCommit="false"
    p:transactionIsolation="8"
    p:leakDetectionThreshold="300000"
    p:maximumPoolSize="4"
    p:maxLifetime="28000000"
    />

Recommend you leave that as the default value.

--Daniel Fisher
 

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]

smime.p7s (8K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Shibboleth and database connection leak

Tobias Galéus
In reply to this post by Tobias Galéus
I've investigated this a bit further. Shibboleth reports a deadlock:

2018-07-06 10:59:19,552 - INFO
[net.shibboleth.idp.authn.impl.ValidateUsernamePasswordAgainstLDAP:152] -
Profile Action ValidateUsernamePasswordAgainstLDAP: Login by 'gusgXXXXX'
succeeded|130.xxx.xx.xxx|
2018-07-06 10:59:19,642 - WARN
[org.hibernate.engine.jdbc.spi.SqlExceptionHelper:144] - SQL Error: 1213,
SQLState: 40001|130.xxx.xx.xxx|
2018-07-06 10:59:19,643 - ERROR
[org.hibernate.engine.jdbc.spi.SqlExceptionHelper:146] - Deadlock found when
trying to get lock; try restarting transaction|130.xxx.xx.xxx|

SQL Queries during that period of time (I've masked usernames, IPs and
tickets):
https://pastebin.com/TpaWm8C8

I'm using Hikari CP and configured it to report leaks after 5 minutes. So
after 5 minutes hikari logs a leak:
11:04:19.645 [HikariPool-1 housekeeper] Connection leak detection triggered
for com.mysql.jdbc.JDBC4Connection@44309e77 on thread qtp721748895-1747,
stack trace follows
java.lang.Exception: Apparent connection leak detected

Current configuration in global.xml:

    <bean id="shibboleth.JPAStorageService.DataSource"
    class="com.zaxxer.hikari.HikariDataSource" destroy-method="close"
lazy-init="true"
    p:driverClassName="com.mysql.jdbc.Driver"
   
p:jdbcUrl="jdbc:mysql://127.0.0.1:3306/shibboleth?cachePrepStmts=true&amp;prepStmtCacheSize=250&amp;prepStmtCacheSqlLimit=2048&amp;cachePrepStmts=true&amp;useServerPrepStmts=true"
    p:username="shibboleth"
    p:password="REMOVED"
    p:autoCommit="false"
    p:transactionIsolation="TRANSACTION_SERIALIZABLE"
    p:leakDetectionThreshold="300000"
    p:maximumPoolSize="4"
    p:maxLifetime="600000"
    p:idleTimeout="300000"
    />


Is this a Shibboleth bug or a configuration error on my part? How can I
investigate this further?

Best regards,
Tobias



--
Sent from: http://shibboleth.1660669.n2.nabble.com/Shibboleth-Users-f1660767.html
--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]
Reply | Threaded
Open this post in threaded view
|

RE: Shibboleth and database connection leak

Cantor, Scott E.
> I've investigated this a bit further. Shibboleth reports a deadlock:

No, it's the database refusing to take locks properly to serialize the transaction. All our code supports retry logic based on driver error codes, as documented.

I have no idea what any of that has to do with a leak, that's a bug in one of those libraries or a meaningless message.

-- Scott

--
For Consortium Member technical support, see https://wiki.shibboleth.net/confluence/x/coFAAg
To unsubscribe from this list send an email to [hidden email]