java.util.NoSuchElementException: Pool exhausted #2

[mafrankowski]

I've got following exception (same as reported in https://github.com/messaginghub/pooled-jms/issues/15) from the latest pooled-jms code (3.1.0) as well as from version 1.2.4: java.util.NoSuchElementException: Pool exhausted at org.apache.commons.pool2.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:457) at org.apache.commons.pool2.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:350) at org.messaginghub.pooled.jms.JmsPoolConnectionFactory.createJmsPoolConnection(JmsPoolConnectionFactory.java:716)

or from version 1.2.4 at org.messaginghub.pooled.jms.JmsPoolConnectionFactory.createJmsPoolConnection(JmsPoolConnectionFactory.java:732)

Please use the same test method to reproduce the issue as reported in previous related issue - it should be added to org.messaginghub.pooled.jms.JmsPoolConnectionFactoryTest, optionally changing 1ms to 2ms as below because in case of 1ms it sometimes fails somewhere else. This is random issue so sometimes this tests fails sometimes it passes.

@Test
public void testCreateConnectionWithIdleTimeoutAndCheckInterval() throws Exception {
    cf.setConnectionIdleTimeout(2);
    cf.setConnectionCheckInterval(2);
    for (int i = 0;i< 10000;++i){
        Connection connection = cf.createConnection();
        assertNotNull(connection);
        connection.close();
        Thread.sleep(2);
    }
}

[mafrankowski]

Attaching also test trace logs:

2023-07-07 12:02:24,251 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Created new connection: ConnectionPool[org.messaginghub.pooled.jms.mock.MockJMSConnection@20580d4e]

2023-07-07 12:02:24,253 [commons-pool-evictor] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Connection has expired or was closed: ConnectionPool[null] and will be destroyed

2023-07-07 12:02:24,253 [commons-pool-evictor] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Destroying connection: ConnectionPool[null]

2023-07-07 12:02:24,253 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Created new connection: ConnectionPool[org.messaginghub.pooled.jms.mock.MockJMSConnection@4b432e53]

2023-07-07 12:02:24,255 [commons-pool-evictor] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Connection has expired or was closed: ConnectionPool[null] and will be destroyed

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 1 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 2 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 3 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 4 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 5 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 6 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [commons-pool-evictor] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Destroying connection: ConnectionPool[null]

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 7 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 8 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 9 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,255 [main] TRACE org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Recover attempt 10 from exhausted pool by refilling pool key and creating new Connection

2023-07-07 12:02:24,266 [main] DEBUG org.messaginghub.pooled.jms.JmsPoolConnectionFactory - Stopping the JmsPoolConnectionFactory, number of connections in cache: 0

2023-07-07 12:02:24,267 [main] INFO org.messaginghub.pooled.jms.JmsPoolTestSupport - ========== finished test testCreateConnectionWithIdleTimeoutAndCheckInterval() ==========

[tabish121]

I'm unable to reproduce this using the test provided.

[mafrankowski]

Please find a little bit changed test attached, hope you will be able to reproduce it with this one. When I run it locally I get at least few failures out of 10 retries defined (checked it now on version 3.1.2-SNAPSHOT). Additionally it looks that changing logging to org.slf4j.simpleLogger.log.org.messaginghub.pooled.jms=TRACE even increase probability of failure. This issue also occurs on production around once a month, of course with a little bit more appropriate eviction parameters.

JmsPoolConnectionNoSuchElementExceptionTest.zip

[tabish121]

Testing on the latest release you would reproduce this as the pool will throw an JMS ResourceAllocationException if you force into such a situation. Setting an idle timeout of 1 will overwhelm the pool management when creating massive numbers of connections at the same time and the pool will throw an error to indicate same. This isn't a bug but a reaction to improper configuration of the pool.

[mafrankowski]

I put idle timeout as 1 in test only to increase chances to reproduce it. I observe the same issue around once every month on production (which is very rare but still) for following configuration

pooledConnectionFactory.setConnectionIdleTimeout(200_000); pooledConnectionFactory.setConnectionCheckInterval(200_000);

[mafrankowski]

It seems that adding Thread.yield() line as below in JmsPoolConnectionFactory somehow fixes the issue from test, but it is just a guess as I do not understand that logic with 10 retries when NoSuchElementException is thrown

                        if (exhaustedPoolRecoveryAttempts++ < exhaustionRecoverAttemptLimit) {
                            LOG.trace("Recover attempt {} from exhausted pool by refilling pool key and creating new Connection", exhaustedPoolRecoveryAttempts);
                            connectionsPool.addObject(key);
                            Thread.yield();
                            continue;
                        } else {

[tabish121]

I've released version 3.1.2 with some improvements in this area to attempt to resolve this however in a worst case scenario it can still throw ResourceAllocationException errors if it cannot obtain a factory without blocking for to long.