You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Francesco Nigro (Jira)" <ji...@apache.org> on 2022/02/10 16:10:00 UTC

[jira] [Updated] (ARTEMIS-3679) Brokers shutdown after daylight saving fall back

     [ https://issues.apache.org/jira/browse/ARTEMIS-3679?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Francesco Nigro updated ARTEMIS-3679:
-------------------------------------
    Description: 
This is what happened on a two brokers JDBC shared-store setup after daylight savings change. This also causes the backup shutdown with the same critical IO error.
{code:java}
2021-10-31 01:58:44,002 WARN [org.apache.activemq.artemis.core.server.impl.jdbc.JdbcLeaseLock] [LIVE] d5b17659-c4f6-4847-bfb2-6c5f209a0fb9 query currentTimestamp = 2021-10-31 01:58:43.999927 on database should happen AFTER 2021-10-31 01:58:44.0 on broker 2021-10-31 02:59:00,217 WARN [org.apache.activemq.artemis.core.server] AMQ222010: Critical IO Error, shutting down the server. file=NULL, message=Lost NodeManager lock: java.io.IOException: lost lock at org.apache.activemq.artemis.core.server.impl.SharedStoreLiveActivation.lambda$registerActiveLockListener$0(SharedStoreLiveActivation.java:123) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.NodeManager.lambda$notifyLostLock$0(NodeManager.java:143) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at java.base/java.lang.Iterable.forEach(Iterable.java:75) [java.base:] at org.apache.activemq.artemis.core.server.NodeManager.notifyLostLock(NodeManager.java:141) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.impl.jdbc.JdbcNodeManager.notifyLostLock(JdbcNodeManager.java:154) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.impl.jdbc.ActiveMQScheduledLeaseLock.run(ActiveMQScheduledLeaseLock.java:114) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.runForExecutor(ActiveMQScheduledComponent.java:313) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.lambda$bookedRunForScheduler$2(ActiveMQScheduledComponent.java:320) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:65) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [java.base:] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [java.base:] at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] 
{code}
The reason seems related to the TIMESTAMP field used on HOLDER_EXPIRATION_TIME: given that it doesn't contains any time zone information, if it compares against TIMESTAMP WITH TIME ZONE values ie CURRENT_TIMESTAMP query results, they won't work as expected.

In addition, CURRENT_TIMESTAMP values, while converted into the Java world, reports UTC time values, while TIMESTAMP ones are adjusted depending by the actual time zone (sensitive to day saving time adjustment as well!).

 

 

  was:
This is what happened on a two brokers JDBC shared-store setup after daylight savings change. This also causes the backup shutdown with the same critical IO error.

 
{code:java}
2021-10-31 01:58:44,002 WARN [org.apache.activemq.artemis.core.server.impl.jdbc.JdbcLeaseLock] [LIVE] d5b17659-c4f6-4847-bfb2-6c5f209a0fb9 query currentTimestamp = 2021-10-31 01:58:43.999927 on database should happen AFTER 2021-10-31 01:58:44.0 on broker 2021-10-31 02:59:00,217 WARN [org.apache.activemq.artemis.core.server] AMQ222010: Critical IO Error, shutting down the server. file=NULL, message=Lost NodeManager lock: java.io.IOException: lost lock at org.apache.activemq.artemis.core.server.impl.SharedStoreLiveActivation.lambda$registerActiveLockListener$0(SharedStoreLiveActivation.java:123) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.NodeManager.lambda$notifyLostLock$0(NodeManager.java:143) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at java.base/java.lang.Iterable.forEach(Iterable.java:75) [java.base:] at org.apache.activemq.artemis.core.server.NodeManager.notifyLostLock(NodeManager.java:141) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.impl.jdbc.JdbcNodeManager.notifyLostLock(JdbcNodeManager.java:154) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.impl.jdbc.ActiveMQScheduledLeaseLock.run(ActiveMQScheduledLeaseLock.java:114) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.runForExecutor(ActiveMQScheduledComponent.java:313) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.lambda$bookedRunForScheduler$2(ActiveMQScheduledComponent.java:320) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:65) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [java.base:] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [java.base:] at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] 
{code}
 


> Brokers shutdown after daylight saving fall back
> ------------------------------------------------
>
>                 Key: ARTEMIS-3679
>                 URL: https://issues.apache.org/jira/browse/ARTEMIS-3679
>             Project: ActiveMQ Artemis
>          Issue Type: Bug
>    Affects Versions: 2.20.0
>            Reporter: Francesco Nigro
>            Assignee: Francesco Nigro
>            Priority: Major
>
> This is what happened on a two brokers JDBC shared-store setup after daylight savings change. This also causes the backup shutdown with the same critical IO error.
> {code:java}
> 2021-10-31 01:58:44,002 WARN [org.apache.activemq.artemis.core.server.impl.jdbc.JdbcLeaseLock] [LIVE] d5b17659-c4f6-4847-bfb2-6c5f209a0fb9 query currentTimestamp = 2021-10-31 01:58:43.999927 on database should happen AFTER 2021-10-31 01:58:44.0 on broker 2021-10-31 02:59:00,217 WARN [org.apache.activemq.artemis.core.server] AMQ222010: Critical IO Error, shutting down the server. file=NULL, message=Lost NodeManager lock: java.io.IOException: lost lock at org.apache.activemq.artemis.core.server.impl.SharedStoreLiveActivation.lambda$registerActiveLockListener$0(SharedStoreLiveActivation.java:123) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.NodeManager.lambda$notifyLostLock$0(NodeManager.java:143) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at java.base/java.lang.Iterable.forEach(Iterable.java:75) [java.base:] at org.apache.activemq.artemis.core.server.NodeManager.notifyLostLock(NodeManager.java:141) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.impl.jdbc.JdbcNodeManager.notifyLostLock(JdbcNodeManager.java:154) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.impl.jdbc.ActiveMQScheduledLeaseLock.run(ActiveMQScheduledLeaseLock.java:114) [artemis-server-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.runForExecutor(ActiveMQScheduledComponent.java:313) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.lambda$bookedRunForScheduler$2(ActiveMQScheduledComponent.java:320) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:65) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [java.base:] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [java.base:] at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.16.0.redhat-00012.jar:2.16.0.redhat-00012] 
> {code}
> The reason seems related to the TIMESTAMP field used on HOLDER_EXPIRATION_TIME: given that it doesn't contains any time zone information, if it compares against TIMESTAMP WITH TIME ZONE values ie CURRENT_TIMESTAMP query results, they won't work as expected.
> In addition, CURRENT_TIMESTAMP values, while converted into the Java world, reports UTC time values, while TIMESTAMP ones are adjusted depending by the actual time zone (sensitive to day saving time adjustment as well!).
>  
>  



--
This message was sent by Atlassian Jira
(v8.20.1#820001)