GEODE-6588: Fixed mismatch of placeholders and arguments #7375

nabarunnag · 2022-02-16T22:20:49Z

Logging calls with number of placeholder not equal to the number of
arguments were fixed in this PR.

For all changes:

Is there a JIRA ticket associated with this PR? Is it referenced in the commit message?
Has your PR been rebased against the latest commit within the target branch (typically develop)?
Is your initial contribution a single, squashed commit?
Does gradlew build run cleanly?
Have you written or updated unit tests to verify your changes?
If adding new dependencies to the code, are these dependencies licensed in a way that is compatible for inclusion under ASF 2.0?

...core/src/distributedTest/java/org/apache/geode/internal/jta/dunit/LoginTimeOutDUnitTest.java

geode-core/src/main/java/org/apache/geode/cache/client/internal/QueueStateImpl.java

jake-at-work · 2022-02-16T22:33:56Z

geode-core/src/main/java/org/apache/geode/internal/cache/EntryExpiryTask.java

@@ -328,8 +328,8 @@ protected void basicPerformTimeout(boolean isPending) throws CacheException {
          if (logger.isTraceEnabled()) {
            // NOTE: original finer message used this.toString() twice


I don't this comment is necessary anymore.

will remove

jake-at-work · 2022-02-16T22:35:01Z

geode-core/src/main/java/org/apache/geode/internal/cache/PartitionedRegionDataStore.java

@@ -1257,7 +1257,7 @@ boolean canAccommodateMoreBytesSafely(int bytes) {
    final long curBytes = bytesInUse.get();
    if (isDebugEnabled) {
      logger.debug(
-          "canAccomodateMoreBytes: bytes = {} allocatedMemory = {} newAllocatedSize = {} thresholdSize = ",
+          "canAccomodateMoreBytes: bytes ={} allocatedMemory ={} newAllocatedSize ={} thresholdSize ={}",


Was it intentional to remove the whitespace here?

was trying to keep the spacing unform in a way. There are no spaces in ':{}' (sometimes they do) hence was trying to keep things uniform.

If removing whitespace, x=5 y=7 seems more natural than x =5 y =7 🤷‍♂️

jake-at-work · 2022-02-16T22:35:25Z

geode-core/src/main/java/org/apache/geode/internal/cache/PartitionedRegionDataStore.java

@@ -3022,7 +3022,7 @@ public void handleInterestEvent(InterestRegistrationEvent event) {
        // If this is a registration event, add interest for this key
        if (isRegister) {
          if (logger.isDebugEnabled()) {
-            logger.debug("PartitionedRegionDataStore for {} adding interest for: ",
+            logger.debug("PartitionedRegionDataStore for {} adding interest for :{}",


Whitespace change seems wrong.

if we search for :{} in the project, we see that it is being used. I remember all logs I analyzed in hydra we used this format. Helps in easier greps

jake-at-work · 2022-02-16T22:36:25Z

geode-core/src/main/java/org/apache/geode/internal/cache/UpdateAttributesProcessor.java

@@ -462,7 +462,7 @@ public static void send(InternalDistributedMember recipient, int processorId,
      if (exception != null) {
        m.setException(exception);
        if (logger.isDebugEnabled()) {
-          logger.debug("Replying with exception: {}" + m, exception);
+          logger.debug("Replying with exception:{}", m, exception);


I wonder if the intent was for just the exception message here and not the stack.

I think it is safe as it is inside debug flag

jake-at-work · 2022-02-16T22:36:39Z

...rc/main/java/org/apache/geode/internal/cache/execute/ServerToClientFunctionResultSender.java

@@ -98,7 +98,7 @@ public synchronized void lastResult(Object oneResult) {
    }

    if (logger.isDebugEnabled()) {
-      logger.debug("ServerToClientFunctionResultSender sending last result1 {} " + oneResult);
+      logger.debug("ServerToClientFunctionResultSender sending last result1 {} ", oneResult);


Trailing whitespace.

jake-at-work · 2022-02-16T22:37:10Z

geode-core/src/main/java/org/apache/geode/internal/cache/locks/TXLessorDepartureHandler.java

-        logger.warn("Unable to schedule background cleanup of transactions for departed member {}."
-            + "  Performing in-line cleanup of the transactions.");
+        logger.warn(
+            "Unable to schedule background cleanup of transactions for departed member. Performing in-line cleanup of the transactions.");


Is there a member to log here?

found it. adding it to the log

upthewaterspout

I think you accidentally picked up all of the places where we are trying to log the full stack of an exception.

For example - this was correct and will log the full stack trace

logger.debug("I saw an exception", e)

But you changed many of these to this, which will lose the whole stack trace:

logger.debug("I saw an exception {}", e)

upthewaterspout

Sorry Naba - I was reading those messages backwards.

onichols-pivotal

comment deleted

dschneider-pivotal

I had a few comments for you to consider but didn't see anything that had to be changed. It does seem like a common theme is confusion about the last parameter and if it should be logged as an exception stack or just part of the message. It seems like our use of the log4j Logger interface would make it hard to cleanup this ambiguity.

dschneider-pivotal · 2022-02-25T17:51:15Z

geode-core/src/main/java/org/apache/geode/internal/cache/PartitionedRegion.java

@@ -5126,8 +5126,8 @@ public static void validatePRID(InternalDistributedMember sender, int prId, Stri
        PartitionedRegion pr = (PartitionedRegion) o;
        if (pr.getPRId() == prId) {
          if (!pr.getRegionIdentifier().equals(regionId)) {
-            logger.warn("{} is using PRID {} for {} but this process maps that PRID to {}",
-                new Object[] {sender.toString(), prId, pr.getRegionIdentifier()});
+            logger.warn("{} is using PRID {} for regionId {} but this process maps that PRID to {}",


could "sender.toString()" just be "sender"? This will improve performance if warnings are disabled (which is unlikely).

dschneider-pivotal · 2022-02-25T18:02:59Z

geode-core/src/main/java/org/apache/geode/internal/cache/PartitionedRegion.java

@@ -5613,7 +5613,7 @@ public void cleanupFailedInitialization() {
    }
    if (savedFirstRuntimeException != null
        && savedFirstRuntimeException instanceof DistributedSystemDisconnectedException) {
-      logger.warn("cleanupFailedInitialization originally failed with {}",
+      logger.warn("cleanupFailedInitialization originally failed with: ",


Did the old code for this warning log the call stack for savedFirstRuntimeException? It looks like the intent was just to log savedFirstRuntimeException.toString() inside the curly brackets.
But if the old behavior was to log the stack then I think your change is good.

All the places we consider setting savedFirstRuntimeException we also log a warning with the full stack. So I think that intent of this message was just to say "cleanup actually did fail and here is the exception of all the ones we already logged that caused the failure". It seems odd to me that these are warnings. I'm not sure what a customer could do with these warnings.

I like having the stack on warnings.

dschneider-pivotal · 2022-02-25T18:09:43Z

geode-core/src/main/java/org/apache/geode/internal/cache/tier/sockets/command/Size.java

@@ -72,7 +72,7 @@ public void cmdExecute(final @NotNull Message clientMessage,
    String regionName = regionNamePart.getCachedString();

    if (regionName == null) {
-      logger.warn("The input region name for the %s request is null", "size");
+      logger.warn("The input region name for the size request is null");


while you are in this part of the code consider fixing the errMessage.append call also. It seems like we should just have a local String constant that is in both calls.

Done with #7399

boglesby

A couple minor comments.

boglesby · 2022-03-04T17:00:48Z

geode-core/src/main/java/org/apache/geode/internal/cache/PartitionedRegion.java

@@ -5613,7 +5613,7 @@ public void cleanupFailedInitialization() {
    }
    if (savedFirstRuntimeException != null
        && savedFirstRuntimeException instanceof DistributedSystemDisconnectedException) {
-      logger.warn("cleanupFailedInitialization originally failed with {}",
+      logger.warn("cleanupFailedInitialization originally failed with: ",


I like having the stack on warnings.

boglesby · 2022-03-04T17:02:35Z

geode-core/src/main/java/org/apache/geode/internal/cache/PartitionedRegionDataStore.java

@@ -2953,7 +2953,7 @@ public void executeOnDataStore(final Set localKeys, final Function function, fin
    long start = stats.startFunctionExecution(function.hasResult());
    try {
      if (logger.isDebugEnabled()) {
-        logger.debug("Executing Function: {} on Remote Node with context: ", function.getId(),
+        logger.debug("Executing Function:{} on Remote Node with context: {}", function.getId(),


The space was removed in Function:{}. It probably should also be removed in context: {}

boglesby · 2022-03-04T17:03:36Z

geode-core/src/main/java/org/apache/geode/internal/cache/BucketRegionQueue.java

@@ -146,7 +146,7 @@ private void initializeEventSeqNumQueue() {

        if (logger.isDebugEnabled()) {
          logger.debug(
-              "For bucket {} ,total keys recovered are : {} last key recovered is : {} and the seqNo is ",
+              "For bucket: {} ,total keys recovered are: {} last key recovered is: {} and the seqNo is: {}",


This: {} , should be this: {}, . Also there are no commas in the rest of that message, so maybe the comma should be removed altogether.

jchen21

I recommend some minor changes.

jchen21 · 2022-03-04T17:57:15Z

geode-core/src/main/java/org/apache/geode/internal/cache/UpdateAttributesProcessor.java

@@ -393,7 +393,7 @@ public static void send(InternalDistributedMember recipient, int processorId,
      if (exception != null) {
        m.setException(exception);
        if (logger.isDebugEnabled()) {
-          logger.debug("Replying with exception: {}" + m, exception);
+          logger.debug("Replying with exception: {}", m, exception);


Missing {} here.

jchen21 · 2022-03-04T17:57:25Z

geode-core/src/main/java/org/apache/geode/internal/cache/UpdateAttributesProcessor.java

@@ -462,7 +462,7 @@ public static void send(InternalDistributedMember recipient, int processorId,
      if (exception != null) {
        m.setException(exception);
        if (logger.isDebugEnabled()) {
-          logger.debug("Replying with exception: {}" + m, exception);
+          logger.debug("Replying with exception: {}", m, exception);


Missing {} here.

jchen21 · 2022-03-04T18:17:09Z

geode-core/src/main/java/org/apache/geode/internal/cache/EntryExpiryTask.java

            logger.trace(
-                "{}.performTimeout().getExpirationTime() is {}; {}.expire({}). ttlExpiration: {}, idleExpiration: {}, ttlAttrs: {}, idleAttrs: {} action is: {}",
-                this, expTime, this, action, ttl, idle, getTTLAttributes(), getIdleAttributes());
+                "{}.performTimeout().getExpirationTime() is {}; ttlExpiration:{}, idleExpiration:{}, ttlAttrs:{}, idleAttrs:{} action is:{}",


this is passed as parameter for {}.performTimeout().getExpirationTime(). It will call EntryExpiryTask.toString() which returns a long string description with spaces. It is not easy to read. Perhaps passing this.getClass().getSimpleName() would be better. And the method name should be basicPerformTimeout instead of performTimeout().

Bill

I reviewed the changes in files for which I'm code-owner. Those look perfect. Thanks for the changes @nabarunnag !

nabarunnag · 2022-06-01T04:17:18Z

@boglesby I made sure that stacktrace is always printed in these changes
@dschneider-pivotal I switch to using .warn(String,Throwable) API which ensures the stack is printed as per javadoc

nabarunnag force-pushed the feature/GEODE-6588 branch from 3e5363d to aa49263 Compare February 16, 2022 22:23

DonalEvans approved these changes Feb 16, 2022

View reviewed changes

jake-at-work requested changes Feb 16, 2022

View reviewed changes

upthewaterspout requested changes Feb 16, 2022

View reviewed changes

nabarunnag force-pushed the feature/GEODE-6588 branch from aa49263 to 2804752 Compare February 16, 2022 23:21

upthewaterspout approved these changes Feb 17, 2022

View reviewed changes

nabarunnag force-pushed the feature/GEODE-6588 branch 2 times, most recently from b62b83f to 8dbc866 Compare February 17, 2022 18:29

nabarunnag marked this pull request as ready for review February 23, 2022 23:16

nabarunnag requested review from agingade, BenjaminPerryRoss, jchen21, jdeppe-pivotal, jinmeiliao, kirklund, mhansonp, boglesby, pivotal-eshu, gesterzhou, dschneider-pivotal, Bill, echobravopapa and kamilla1201 as code owners February 23, 2022 23:16

onichols-pivotal reviewed Feb 23, 2022

View reviewed changes

onichols-pivotal requested a review from albertogpz February 23, 2022 23:21

kamilla1201 approved these changes Feb 24, 2022

View reviewed changes

dschneider-pivotal approved these changes Feb 25, 2022

View reviewed changes

nabarunnag requested a review from jake-at-work February 25, 2022 18:24

jinmeiliao approved these changes Feb 28, 2022

View reviewed changes

mhansonp approved these changes Mar 3, 2022

View reviewed changes

jake-at-work approved these changes Mar 3, 2022

View reviewed changes

boglesby approved these changes Mar 4, 2022

View reviewed changes

jchen21 approved these changes Mar 4, 2022

View reviewed changes

kirklund approved these changes Apr 7, 2022

View reviewed changes

Bill approved these changes Apr 8, 2022

View reviewed changes

pivotal-eshu approved these changes Apr 27, 2022

View reviewed changes

GEODE-6588: Fixed mismatch of placeholders and arguments

f257f65

nabarunnag force-pushed the feature/GEODE-6588 branch from 8dbc866 to f257f65 Compare June 1, 2022 03:44

nabarunnag merged commit 992208e into apache:develop Jun 1, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

GEODE-6588: Fixed mismatch of placeholders and arguments #7375

GEODE-6588: Fixed mismatch of placeholders and arguments #7375

nabarunnag commented Feb 16, 2022

jake-at-work Feb 16, 2022

nabarunnag Feb 16, 2022

jake-at-work Feb 16, 2022

nabarunnag Feb 16, 2022

onichols-pivotal Feb 24, 2022

jake-at-work Feb 16, 2022

nabarunnag Feb 16, 2022

jake-at-work Feb 16, 2022

nabarunnag Feb 16, 2022

jake-at-work Feb 16, 2022

nabarunnag Feb 16, 2022

jake-at-work Feb 16, 2022

nabarunnag Feb 16, 2022

upthewaterspout left a comment

upthewaterspout left a comment

onichols-pivotal left a comment •

edited

dschneider-pivotal left a comment

dschneider-pivotal Feb 25, 2022

dschneider-pivotal Feb 25, 2022

boglesby Mar 4, 2022

dschneider-pivotal Feb 25, 2022

nabarunnag Feb 28, 2022

boglesby left a comment

boglesby Mar 4, 2022

boglesby Mar 4, 2022

boglesby Mar 4, 2022

jchen21 left a comment

jchen21 Mar 4, 2022

jchen21 Mar 4, 2022

jchen21 Mar 4, 2022

Bill left a comment

nabarunnag commented Jun 1, 2022

		@@ -328,8 +328,8 @@ protected void basicPerformTimeout(boolean isPending) throws CacheException {
		if (logger.isTraceEnabled()) {
		// NOTE: original finer message used this.toString() twice

GEODE-6588: Fixed mismatch of placeholders and arguments #7375

GEODE-6588: Fixed mismatch of placeholders and arguments #7375

Conversation

nabarunnag commented Feb 16, 2022

For all changes:

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

upthewaterspout left a comment

Choose a reason for hiding this comment

upthewaterspout left a comment

Choose a reason for hiding this comment

onichols-pivotal left a comment • edited

Choose a reason for hiding this comment

dschneider-pivotal left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

boglesby left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jchen21 left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Bill left a comment

Choose a reason for hiding this comment

nabarunnag commented Jun 1, 2022

onichols-pivotal left a comment •

edited