gemmellr commented on code in PR #4418:
URL: https://github.com/apache/activemq-artemis/pull/4418#discussion_r1159551573
##########
artemis-core-client/src/main/java/org/apache/activemq/artemis/api/core/RefCountMessage.java:
##########
@@ -16,13 +16,109 @@
*/
package org.apache.activemq.artemis.api.core;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.lang.invoke.MethodHandles;
+import java.time.Instant;
+import java.util.ArrayList;
import java.util.HashMap;
import java.util.concurrent.atomic.AtomicIntegerFieldUpdater;
-// import org.apache.activemq.artemis.utils.collections.ConcurrentHashSet; --
#ifdef DEBUG
+import org.apache.activemq.artemis.core.client.ActiveMQClientLogger;
+import org.apache.activemq.artemis.utils.ObjectCleaner;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.helpers.MessageFormatter;
public class RefCountMessage {
+ /** If you define a logger named
org.apache.activemq.artemis.api.core.RefCountMessage.REF_DEBUG at at least
DEBUG level
+ you will see logging output when this object is released without being
accounted for. */
+ private static final Logger refLogger =
LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() +
".REF_DEBUG");
+
+ public static boolean isDebugEnabled() {
+ return refLogger.isDebugEnabled();
+ }
+
+ /** Sub classes constructors willing to debug reference counts,
+ * can register the objectCleaner through this method. */
+ protected void registerDebug() {
+ if (debugStatus == null) {
+ debugStatus = new DebugState(this.toString());
+ ObjectCleaner.register(this, debugStatus);
+ }
+ }
+
+ public static boolean isTraceEnabled() {
+ return refLogger.isTraceEnabled();
+ }
+
+
+ private static class DebugState implements Runnable {
+ private final ArrayList<Exception> debugCrumbs = new ArrayList<>();
+
+ // this means the object is accounted for and it should not print any
warnings
+ volatile boolean accounted;
+
+ volatile boolean referenced;
+
+ String description;
+
+ /**
+ * Notice: This runnable cannot hold any reference back to message
otherwise it won't ever happen and you will get a memory leak.
+ * */
+ Runnable runWhenLeaked;
+
+ DebugState(String description) {
+ this.description = description;
+ addDebug("registered");
+ }
+
+ /** this marks the Status as accounted for
+ * and no need to report an issue when DEBUG hits */
+ void accountedFor() {
+ accounted = true;
+ }
+
+ public static String getTime() {
+ return Instant.now().toString();
+ }
Review Comment:
Doesnt seem like it needs to be public (looks odd, even if the class is
private, since almost nothing else is).
##########
artemis-core-client/src/main/java/org/apache/activemq/artemis/api/core/RefCountMessage.java:
##########
@@ -16,13 +16,109 @@
*/
package org.apache.activemq.artemis.api.core;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.lang.invoke.MethodHandles;
+import java.time.Instant;
+import java.util.ArrayList;
import java.util.HashMap;
import java.util.concurrent.atomic.AtomicIntegerFieldUpdater;
-// import org.apache.activemq.artemis.utils.collections.ConcurrentHashSet; --
#ifdef DEBUG
+import org.apache.activemq.artemis.core.client.ActiveMQClientLogger;
+import org.apache.activemq.artemis.utils.ObjectCleaner;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.helpers.MessageFormatter;
public class RefCountMessage {
+ /** If you define a logger named
org.apache.activemq.artemis.api.core.RefCountMessage.REF_DEBUG at at least
DEBUG level
+ you will see logging output when this object is released without being
accounted for. */
+ private static final Logger refLogger =
LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() +
".REF_DEBUG");
+
+ public static boolean isDebugEnabled() {
+ return refLogger.isDebugEnabled();
+ }
+
+ /** Sub classes constructors willing to debug reference counts,
+ * can register the objectCleaner through this method. */
+ protected void registerDebug() {
+ if (debugStatus == null) {
+ debugStatus = new DebugState(this.toString());
+ ObjectCleaner.register(this, debugStatus);
+ }
+ }
+
+ public static boolean isTraceEnabled() {
+ return refLogger.isTraceEnabled();
+ }
Review Comment:
Would seem nicer to group the two 'not logging' isEnabled methods.
Calling them isRef\<Foo\>Enabled could also be nicer to help further
disambiguate them from actual regular logging isEnabled checks.
##########
artemis-server/src/main/java/org/apache/activemq/artemis/core/server/impl/QueueImpl.java:
##########
@@ -1108,6 +1109,11 @@ public void addHead(final MessageReference ref, boolean
scheduling) {
if (logger.isTraceEnabled()) {
logger.trace("AddHead, size = {}, intermediate size = {}, references
size = {}\nreference={}", queueMemorySize,
intermediateMessageReferences.size(), messageReferences.size(), ref);
}
+
+ if (RefCountMessage.isTraceEnabled()) {
+ RefCountMessage.deferredDebug(ref.getMessage(), "AddHead queue {}",
this.getName());
Review Comment:
The others seem to be using more of a sentence structure, i.e "add head"
Edit...following the next comment, could alternatively go the other way, and
make them all method-name structured.
##########
artemis-server/src/main/java/org/apache/activemq/artemis/core/server/ActiveMQServerLogger.java:
##########
@@ -815,7 +815,7 @@ void slowConsumerDetected(String sessionID,
@LogMessage(id = 222168, value = "The '" +
TransportConstants.PROTOCOL_PROP_NAME + "' property is deprecated. If you want
this Acceptor to support multiple protocols, use the '" +
TransportConstants.PROTOCOLS_PROP_NAME + "' property, e.g. with value
'CORE,AMQP,STOMP'", level = LogMessage.Level.WARN)
void warnDeprecatedProtocol();
- @LogMessage(id = 222169, value = "You have old legacy clients connected to
the queue {} and we can't disconnect them, these clients may just hang", level
= LogMessage.Level.WARN)
+ @LogMessage(id = 222169, value = "You have old legacy clients connected::{}
and we can't disconnect them, these clients may just hang", level =
LogMessage.Level.WARN)
Review Comment:
the "::" seems a bit odd?
##########
artemis-core-client/src/main/java/org/apache/activemq/artemis/api/core/RefCountMessage.java:
##########
@@ -16,13 +16,109 @@
*/
package org.apache.activemq.artemis.api.core;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.lang.invoke.MethodHandles;
+import java.time.Instant;
+import java.util.ArrayList;
import java.util.HashMap;
import java.util.concurrent.atomic.AtomicIntegerFieldUpdater;
-// import org.apache.activemq.artemis.utils.collections.ConcurrentHashSet; --
#ifdef DEBUG
+import org.apache.activemq.artemis.core.client.ActiveMQClientLogger;
+import org.apache.activemq.artemis.utils.ObjectCleaner;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.helpers.MessageFormatter;
public class RefCountMessage {
+ /** If you define a logger named
org.apache.activemq.artemis.api.core.RefCountMessage.REF_DEBUG at at least
DEBUG level
+ you will see logging output when this object is released without being
accounted for. */
+ private static final Logger refLogger =
LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() +
".REF_DEBUG");
+
+ public static boolean isDebugEnabled() {
+ return refLogger.isDebugEnabled();
+ }
+
+ /** Sub classes constructors willing to debug reference counts,
+ * can register the objectCleaner through this method. */
+ protected void registerDebug() {
+ if (debugStatus == null) {
+ debugStatus = new DebugState(this.toString());
+ ObjectCleaner.register(this, debugStatus);
+ }
+ }
+
+ public static boolean isTraceEnabled() {
+ return refLogger.isTraceEnabled();
+ }
+
+
+ private static class DebugState implements Runnable {
+ private final ArrayList<Exception> debugCrumbs = new ArrayList<>();
+
+ // this means the object is accounted for and it should not print any
warnings
+ volatile boolean accounted;
+
+ volatile boolean referenced;
+
+ String description;
+
+ /**
+ * Notice: This runnable cannot hold any reference back to message
otherwise it won't ever happen and you will get a memory leak.
+ * */
+ Runnable runWhenLeaked;
+
+ DebugState(String description) {
+ this.description = description;
+ addDebug("registered");
+ }
+
+ /** this marks the Status as accounted for
+ * and no need to report an issue when DEBUG hits */
+ void accountedFor() {
+ accounted = true;
+ }
+
+ public static String getTime() {
+ return Instant.now().toString();
+ }
+
+ void addDebug(String event) {
+ debugCrumbs.add(new Exception(event + " at " + getTime()));
+ if (accounted) {
+ refLogger.debug("Message Previously Released {}, {}, \n{}",
description, event, debugLocations());
+ }
+ }
+
+ void up(String description) {
+ referenced = true;
+ debugCrumbs.add(new Exception("up:" + description + " at " +
getTime()));
+ }
+
+ void down(String description) {
+ debugCrumbs.add(new Exception("down:" + description + " at " +
getTime()));
+ }
+
+ @Override
+ public void run() {
+ if (!accounted && referenced) {
+ runWhenLeaked.run();
+ refLogger.debug("Message Leaked reference counting{}\n{}",
description, debugLocations());
+ }
+ }
+
+ public String debugLocations() {
+ StringWriter writer = new StringWriter();
+ PrintWriter out = new PrintWriter(writer);
+ out.println("Locations:");
+ debugCrumbs.forEach(e -> e.printStackTrace(out));
Review Comment:
Every time I see "out.println("Locations:");" I think its writing to system
out, before I look at the variables and realise it isn't. Renaming 'out' might
help :)
##########
artemis-server/src/main/java/org/apache/activemq/artemis/core/server/impl/ServerConsumerImpl.java:
##########
@@ -1078,21 +1088,26 @@ public synchronized MessageReference
removeReferenceByID(final long messageID) t
// This is an optimization, if the reference is the first one, we
just poll it.
// But first we need to make sure deliveringRefs isn't empty
if (deliveringRefs.isEmpty()) {
+ if (logger.isTraceEnabled()) {
+ logger.trace("removeReferenceByID {} return null", messageID);
+ }
Review Comment:
Seems odd to gate this one, and not gate the few similar ones added in the
next 20 lines below.
##########
artemis-core-client/src/main/java/org/apache/activemq/artemis/api/core/RefCountMessage.java:
##########
@@ -16,13 +16,109 @@
*/
package org.apache.activemq.artemis.api.core;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.lang.invoke.MethodHandles;
+import java.time.Instant;
+import java.util.ArrayList;
import java.util.HashMap;
import java.util.concurrent.atomic.AtomicIntegerFieldUpdater;
-// import org.apache.activemq.artemis.utils.collections.ConcurrentHashSet; --
#ifdef DEBUG
+import org.apache.activemq.artemis.core.client.ActiveMQClientLogger;
+import org.apache.activemq.artemis.utils.ObjectCleaner;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.helpers.MessageFormatter;
public class RefCountMessage {
+ /** If you define a logger named
org.apache.activemq.artemis.api.core.RefCountMessage.REF_DEBUG at at least
DEBUG level
+ you will see logging output when this object is released without being
accounted for. */
+ private static final Logger refLogger =
LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() +
".REF_DEBUG");
+
+ public static boolean isDebugEnabled() {
+ return refLogger.isDebugEnabled();
+ }
+
+ /** Sub classes constructors willing to debug reference counts,
+ * can register the objectCleaner through this method. */
+ protected void registerDebug() {
+ if (debugStatus == null) {
+ debugStatus = new DebugState(this.toString());
+ ObjectCleaner.register(this, debugStatus);
+ }
+ }
+
+ public static boolean isTraceEnabled() {
+ return refLogger.isTraceEnabled();
+ }
+
+
+ private static class DebugState implements Runnable {
+ private final ArrayList<Exception> debugCrumbs = new ArrayList<>();
+
+ // this means the object is accounted for and it should not print any
warnings
+ volatile boolean accounted;
+
+ volatile boolean referenced;
+
+ String description;
+
+ /**
+ * Notice: This runnable cannot hold any reference back to message
otherwise it won't ever happen and you will get a memory leak.
+ * */
+ Runnable runWhenLeaked;
+
+ DebugState(String description) {
+ this.description = description;
+ addDebug("registered");
+ }
+
+ /** this marks the Status as accounted for
+ * and no need to report an issue when DEBUG hits */
+ void accountedFor() {
+ accounted = true;
+ }
+
+ public static String getTime() {
+ return Instant.now().toString();
+ }
+
+ void addDebug(String event) {
+ debugCrumbs.add(new Exception(event + " at " + getTime()));
+ if (accounted) {
+ refLogger.debug("Message Previously Released {}, {}, \n{}",
description, event, debugLocations());
+ }
+ }
+
+ void up(String description) {
+ referenced = true;
+ debugCrumbs.add(new Exception("up:" + description + " at " +
getTime()));
+ }
+
+ void down(String description) {
+ debugCrumbs.add(new Exception("down:" + description + " at " +
getTime()));
+ }
+
+ @Override
+ public void run() {
+ if (!accounted && referenced) {
+ runWhenLeaked.run();
+ refLogger.debug("Message Leaked reference counting{}\n{}",
description, debugLocations());
+ }
+ }
+
+ public String debugLocations() {
Review Comment:
ditto
##########
artemis-server/src/main/java/org/apache/activemq/artemis/core/server/cluster/impl/Redistributor.java:
##########
@@ -135,6 +140,12 @@ public void proceedDeliver(MessageReference ref) {
// no op
}
+
+ @Override
+ public void failed(Throwable message) {
Review Comment:
Ditto
##########
artemis-server/src/main/java/org/apache/activemq/artemis/core/server/Consumer.java:
##########
@@ -93,6 +93,8 @@ default Binding getBinding() {
*/
void disconnect();
+ void failed(Throwable message);
Review Comment:
'message seems odd...'t' or 'cause' or something would seem a better fit
##########
artemis-server/src/main/java/org/apache/activemq/artemis/core/server/impl/QueueImpl.java:
##########
@@ -1130,9 +1136,14 @@ public void addHead(final MessageReference ref, boolean
scheduling) {
/* Called when a message is cancelled back into the queue */
@Override
public void addSorted(final MessageReference ref, boolean scheduling) {
+ if (RefCountMessage.isTraceEnabled()) {
+ RefCountMessage.deferredDebug(ref.getMessage(), "returning to queue
{}", this.getAddress());
Review Comment:
There are a few "returning to queue" events. Although they can be separated
by the stacktrace detail it would probably be nicer to make the text more
distinct to begin with, and help out the poor sod digging through streams of
stacktraces later.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
