[
https://issues.apache.org/jira/browse/ARTEMIS-3489?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17436056#comment-17436056
]
Gary Tully edited comment on ARTEMIS-3489 at 10/29/21, 4:16 PM:
----------------------------------------------------------------
It looks like the problem is the lease timeout is just too low, the update with
10ms duration calculated from current time expires before the statement to
execute is processed and it then fails the update condition.
the test seems ok, but I think we need to push up the lease duration.
at time: 16:48:08,306, before the update execute the expirationTime
16:48:08.114 is behind!
{code:java}
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper@662936a.prepareStatement(UPDATE
NODE_MANAGER_STORE SET HOLDER_EXPIRATION_TIME = ? WHERE HOLDER_ID = ? AND
HOLDER_EXPIRATION_TIME IS NOT NULL AND ? >= HOLDER_EXPIRATION_TIME AND ? >
CURRENT_TIMESTAMP AND ID = 1) =
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper@662936a.prepareStatement(SELECT
CURRENT_TIMESTAMP FROM NODE_MANAGER_STORE) =
org.apache.commons.dbcp2.DelegatingPreparedStatement@7f4c8611
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@7f4c8611.executeQuery() =
org.apache.commons.dbcp2.DelegatingResultSet@30cd738c
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
[email protected]() = true
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingResultSet@30cd738c.getTimestamp(1) =
2021-10-29 16:48:08.104
[main] 16:48:08,306 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
[email protected]()
[main] 16:48:08,306 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@7f4c8611.close()
[main] 16:48:08,306 DEBUG
[org.apache.activemq.artemis.core.server.impl.jdbc.JdbcLeaseLock] [LIVE]
491cf07b-65b3-43b9-99a8-072c99e09fbe is renewing lock with expirationTime =
2021-10-29 16:48:08.114
[main] 16:48:08,306 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setTimestamp(1,
2021-10-29 16:48:08.114)
[main] 16:48:08,307 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setString(2,
491cf07b-65b3-43b9-99a8-072c99e09fbe)
[main] 16:48:08,307 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setTimestamp(3,
2021-10-29 16:48:08.114)
[main] 16:48:08,307 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setTimestamp(4,
2021-10-29 16:48:08.114)
[main] 16:48:08,312 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.executeUpdate() = 0
{code}
was (Author: gtully):
It looks like the problem is the lease timeout is just too low, the update with
10ms duration calculated from current time expires before the statement to
execute is processed and it then fails the update condition.
the test seems ok, but I think we need to push up the lease duration.
{code:java}
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper@662936a.prepareStatement(UPDATE
NODE_MANAGER_STORE SET HOLDER_EXPIRATION_TIME = ? WHERE HOLDER_ID = ? AND
HOLDER_EXPIRATION_TIME IS NOT NULL AND ? >= HOLDER_EXPIRATION_TIME AND ? >
CURRENT_TIMESTAMP AND ID = 1) =
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.PoolingDataSource$PoolGuardConnectionWrapper@662936a.prepareStatement(SELECT
CURRENT_TIMESTAMP FROM NODE_MANAGER_STORE) =
org.apache.commons.dbcp2.DelegatingPreparedStatement@7f4c8611
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@7f4c8611.executeQuery() =
org.apache.commons.dbcp2.DelegatingResultSet@30cd738c
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
[email protected]() = true
[main] 16:48:08,104 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingResultSet@30cd738c.getTimestamp(1) =
2021-10-29 16:48:08.104
[main] 16:48:08,306 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
[email protected]()
[main] 16:48:08,306 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@7f4c8611.close()
[main] 16:48:08,306 DEBUG
[org.apache.activemq.artemis.core.server.impl.jdbc.JdbcLeaseLock] [LIVE]
491cf07b-65b3-43b9-99a8-072c99e09fbe is renewing lock with expirationTime =
2021-10-29 16:48:08.114
[main] 16:48:08,306 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setTimestamp(1,
2021-10-29 16:48:08.114)
[main] 16:48:08,307 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setString(2,
491cf07b-65b3-43b9-99a8-072c99e09fbe)
[main] 16:48:08,307 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setTimestamp(3,
2021-10-29 16:48:08.114)
[main] 16:48:08,307 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.setTimestamp(4,
2021-10-29 16:48:08.114)
[main] 16:48:08,312 TRACE
[org.apache.activemq.artemis.jdbc.store.drivers.JDBCConnectionProvider]
org.apache.commons.dbcp2.DelegatingPreparedStatement@5735f981.executeUpdate() = 0
{code}
> JdbcLeaseLockTest fails sporadically in CI
> ------------------------------------------
>
> Key: ARTEMIS-3489
> URL: https://issues.apache.org/jira/browse/ARTEMIS-3489
> Project: ActiveMQ Artemis
> Issue Type: Test
> Affects Versions: 2.18.0
> Reporter: Robbie Gemmell
> Priority: Major
>
> JdbcLeaseLockTest fails sporadically in CI:
> E.g:
> [https://app.travis-ci.com/github/apache/activemq-artemis/jobs/538004665#L3201]
> [https://github.com/apache/activemq-artemis/runs/3531185223?check_suite_focus=true#step:5:2094]
> https://github.com/apache/activemq-artemis/runs/3507926162?check_suite_focus=true#step:5:2256
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
