[
https://issues.apache.org/jira/browse/ARTEMIS-5047?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17885492#comment-17885492
]
Juan commented on ARTEMIS-5047:
-------------------------------
[~jbertram] I've enabled {{DEBUG}} logging for
{{org.apache.activemq.artemis.core.server.impl.FileLockNodeManager}} as you
suggested, and I believe I've identified the root cause of the issue. The logs
confirm that the timestamp of the lock file ({{{}server.lock{}}}) is being
modified *after the lock is acquired* but before the broker makes any actual
changes.
The {{hasBeenModified()}} method in {{FileLockNodeManager.java}} is detecting
the updated timestamp and falsely triggering the lock loss, even though the
actual lock is still valid ({{{}FileLockImpl[0:{*}9223372036854775807{*}
exclusive valid]{}}}).
{code:java}
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,441 DEBUG [Thread-11
(ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@7463bc9d)]
(ServerConsumerImpl.java:859) - ServerConsumerImpl [id=0, filter=null,
binding=LocalQueueBinding [address=/topic/globalRestartService/config-server,
queue=QueueImpl[name=cc7468a6-6a55-4c06-82e1-cb1a86fbc08c,
postOffice=PostOfficeImpl [server=ActiveMQServerImpl::name=DocShifterMQ],
temp=true]@6f78c9da, filter=null, name=cc7468a6-6a55-4c06-82e1-cb1a86fbc08c,
clusterName=cc7468a6-6a55-4c06-82e1-cb1a86fbc08c7ad6b9f8-7d21-11ef-8d43-0235db376cf6],
closed=false]::FlowControl::Received 1 credits, previous value = 0
currentValue = 1
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 {code}
{code:java}
(ActiveMQ-scheduled-threads)] (FileLockNodeManager.java:542) - Lock appears to
be valid; double check by reading status
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:358) - getting state...
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:403) - trying to lock position: 0
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:407) - locked position: 0
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:428) - lock:
sun.nio.ch.FileLockImpl[0:9223372036854775807 exclusive valid]
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:376) - state: L
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:545) - Lock appears to be valid; triple check by
comparing timestamp
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 DEBUG [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:571) - Lock file
\\Svm1.com.docshifter\c$\message-broker\data\journal\server.lock originally
locked at 2024-09-27T22:41:38.150+0000 was modified at
2024-09-27T22:42:02.581+0000
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:51|27 Sep
2024 22:45:51,776 WARN [Thread-4 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:557) - Lost the lock according to the monitor,
notifying listeners
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:52|27 Sep
2024 22:45:52,127 DEBUG [Thread-4
(ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@7463bc9d)]
{code}
{code:java}
(ActiveMQ-scheduled-threads)] (FileLockNodeManager.java:542) - Lock appears to
be valid; double check by reading status
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 DEBUG [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:358) - getting state...
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 DEBUG [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:403) - trying to lock position: 0
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 DEBUG [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:407) - locked position: 0
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 DEBUG [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:428) - lock:
sun.nio.ch.FileLockImpl[0:9223372036854775807 exclusive valid]
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 DEBUG [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:376) - state: L
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 DEBUG [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:545) - Lock appears to be valid; triple check by
comparing timestamp
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 DEBUG [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:571) - Lock file
\\Svm1.com.docshifter\c$\message-broker\data\journal\server.lock originally
locked at 2024-09-27T22:41:38.150+0000 was modified at
2024-09-27T22:42:02.581+0000
FINEST|4804/0|Service com.docshifter.mq.DocShifterMQ|24-09-27 22:45:53|27 Sep
2024 22:45:53,795 WARN [Thread-3 (ActiveMQ-scheduled-threads)]
(FileLockNodeManager.java:557) - Lost the lock according to the monitor,
notifying listeners{code}
> Lost the lock according to the monitor, notifying listeners
> -----------------------------------------------------------
>
> Key: ARTEMIS-5047
> URL: https://issues.apache.org/jira/browse/ARTEMIS-5047
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: Broker
> Affects Versions: 2.33.0, 2.37.0
> Environment: * *Storage Type:* SMB share hosted on AWS FSxN
> * *Current Version:* NetApp Release 9.14.1P5
> * *Affected Version:* 2.33.0 / 2.37.0
> * *Previous Version:* 2.23.1 (issue not observed)
> Reporter: Juan
> Priority: Major
>
> After upgrading from version 2.23.1 to 2.33.0 the system has started to fail
> due to a lock loss. This issue was not present in the previous version and
> has only surfaced after the upgrade.
> I have seen a similar issue.
> {noformat}
> (AuditLogger_impl.java:2843) - AMQ601767: STOMP connection c3e5b678 for user
> [email protected]:64628 created FINEST|6324/0|Service
> com.docshifter.mq.DocShifterMQ|24-08-22 01:03:51|22 Aug 2024 01:03:51,813
> WARN [Thread-0 (ActiveMQ-scheduled-threads)] (FileLockNodeManager.java:557) -
> Lost the lock according to the monitor, notifying listeners
> FINEST|6324/0|Service com.docshifter.mq.DocShifterMQ|24-08-22 01:03:51|22 Aug
> 2024 01:03:51,813 ERROR [Thread-0 (ActiveMQ-scheduled-threads)]
> (ActiveMQServerLogger_impl.java:805) - AMQ222010: Critical IO Error, shutting
> down the server. file=Lost NodeManager lock, message=NULL
> FINEST|6324/0|Service com.docshifter.mq.DocShifterMQ|24-08-22
> 01:03:51|java.io.IOException: lost lock{noformat}
>
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
For further information, visit: https://activemq.apache.org/contact
