OPENNLP-1450 - Revise log messages in OpenNLP regarding use of variab…

…le substitution (#520)

opennlp-brat-annotator/src/main/java/opennlp/bratann/NameFinderAnnService.java

@@ -81,7 +81,7 @@ public static void main(String[] args) throws Exception {
       } else if ("simple".equals(args[ruleBasedTokenizerIndex])) {
         tokenizer = SimpleTokenizer.INSTANCE;
       } else {
-        logger.error("unknown tokenizer: " + args[ruleBasedTokenizerIndex]);
+        logger.error("unknown tokenizer: {}", args[ruleBasedTokenizerIndex]);
         return;
       }
     }

opennlp-tools/src/main/java/opennlp/tools/cmdline/languagemodel/NGramLanguageModelTool.java

@@ -74,8 +74,8 @@ public void run(String[] args) {
             continue;
           }
 
-          logger.info(Arrays.toString(tokens) + " -> prob:" + probability + ", " +
-                  "next:" + Arrays.toString(predicted));
+          logger.info("{} -> prob: {}, next: {}",
+              Arrays.toString(tokens), probability, Arrays.toString(predicted));
 
           perfMon.incrementCounter();
         }

opennlp-tools/src/main/java/opennlp/tools/cmdline/namefind/NameSampleCountersStream.java

@@ -98,8 +98,9 @@ public void printSummary() {
 
     int totalNames = 0;
     for (Map.Entry<String, Integer> counter : getNameCounters().entrySet()) {
-      logger.info("#" + counter.getKey() + " entities: " + counter.getValue());
+      logger.info("# {} entities: {}", counter.getKey(), counter.getValue());
       totalNames += counter.getValue();
     }
+    logger.info("# total: {}", totalNames);
   }
 }

opennlp-tools/src/main/java/opennlp/tools/cmdline/parser/ParserTool.java

@@ -152,7 +152,7 @@ public void run(String[] args) {
 
             for (int pi = 0, pn = parses.length; pi < pn; pi++) {
               if (showTopK) {
-                logger.debug(pi + " " + parses[pi].getProb() + " ");
+                logger.debug("{} {} ", pi,  parses[pi].getProb());
               }
 
               parses[pi].show();

opennlp-tools/src/main/java/opennlp/tools/formats/brat/BratDocumentParser.java

@@ -148,9 +148,9 @@ public List<NameSample> parse(BratDocument sample) {
               if (nameBeginIndex != null && nameEndIndex != null) {
                 mappedFragments.add(new Span(nameBeginIndex, nameEndIndex, entity.getType()));
               } else {
-                logger.warn("Dropped entity " + entity.getId() + " ("
-                    + entitySpan.getCoveredText(sample.getText()) + ") " + " in document "
-                    + sample.getId() + ", it is not matching tokenization!");
+                logger.warn("Dropped entity {} ({}) in document {} as it is not matching " +
+                        "tokenization!", entity.getId(),
+                    entitySpan.getCoveredText(sample.getText()), sample.getId());
               }
             }
           }

opennlp-tools/src/main/java/opennlp/tools/formats/masc/MascNamedEntityParser.java

@@ -88,8 +88,8 @@ public void startElement(String uri, String localName, String qName, Attributes
         String type = entityIDtoEntityType.get(entityID);
         if (tokenToEntity.containsKey(tokenID) && !type.equals(tokenToEntity.get(tokenID))) {
           logger.warn("One token assigned to different named entity types.\n" +
-              "\tPenn-TokenID: " + tokenID + "\n\tToken types: \"" + type + "\", \"" +
-              tokenToEntity.get(tokenID) + "\"\n\tKeeping only " + "\"type\"");
+              "\tPenn-TokenID: {}\n\tToken types: \"{}\", \"{}\"\n\tKeeping only " + "\"type\"",
+              tokenID, type, tokenToEntity.get(tokenID));
         }
         tokenToEntity.put(tokenID, type);
       }

opennlp-tools/src/main/java/opennlp/tools/formats/masc/MascSentence.java

@@ -243,7 +243,7 @@ boolean addNamedEntities(Map<Integer, String> entityIDtoEntityType,
       Span leftSpan = namedEntities.get(leftIndex);
       Span rightSpan = namedEntities.get(rightIndex);
       if (leftSpan.contains(rightSpan) || leftSpan.crosses(rightSpan)) {
-        logger.warn("Named entities overlap. This is forbidden in the OpenNLP." +
+        logger.warn("Named entities overlap. This is forbidden in OpenNLP." +
             "\n\tKeeping the longer of them.");
         if (rightSpan.length() > leftSpan.length()) {
           overlaps.add(leftIndex);

opennlp-tools/src/main/java/opennlp/tools/ml/maxent/GISTrainer.java

@@ -628,7 +628,7 @@ private double nextIteration(double correctionConstant,
           params[pi].updateParameter(aoi, gaussianUpdate(pi, aoi, correctionConstant));
         } else {
           if (model[aoi] == 0) {
-            logger.warn("Model expects == 0 for " + predLabels[pi] + " " + outcomeLabels[aoi]);
+            logger.warn("Model expects == 0 for {} {}", predLabels[pi], outcomeLabels[aoi]);
           }
           //params[pi].updateParameter(aoi,(StrictMath.log(observed[aoi]) - StrictMath.log(model[aoi])));
           params[pi].updateParameter(aoi, ((StrictMath.log(observed[aoi]) - StrictMath.log(model[aoi]))
@@ -642,7 +642,8 @@ private double nextIteration(double correctionConstant,
       }
     }
 
-    logger.info("{} - loglikelihood=" + loglikelihood + "\t" + ((double) numCorrect / numEvents), iteration);
+    logger.info("{} - loglikelihood={}\t{}",
+        iteration, loglikelihood, ((double) numCorrect / numEvents));
 
     return loglikelihood;
   }

opennlp-tools/src/main/java/opennlp/tools/ml/maxent/quasinewton/QNMinimizer.java

@@ -226,8 +226,8 @@ public double[] minimize(Function function) {
     if (logger.isDebugEnabled()) {
       logger.debug("Solving convex optimization problem.");
       logger.debug("Objective function has {} variable(s).", dimension);
-      logger.debug("Performing " + iterations + " iterations with " +
-          "L1Cost=" + l1Cost + " and L2Cost=" + l2Cost );
+      logger.debug("Performing {} iterations with L1Cost={} and L2Cost={}",
+          iterations, l1Cost, l2Cost);
     }
 
     double[] direction = new double[dimension];
@@ -270,11 +270,10 @@ public double[] minimize(Function function) {
       if (logger.isDebugEnabled()) {
 
         if (evaluator != null) {
-          logger.debug("{}: \t" + lsr.getValueAtNext() + "\t" + lsr.getFuncChangeRate()
-              + "\t" + evaluator.evaluate(lsr.getNextPoint()), iter);
+          logger.debug("{}: \t{}\t{}\t{}", iter,
+              lsr.getValueAtNext(), lsr.getFuncChangeRate(),evaluator.evaluate(lsr.getNextPoint()));
         } else {
-          logger.debug("{}: \t " + lsr.getValueAtNext() +
-              "\t" + lsr.getFuncChangeRate() + "\n", iter);
+          logger.debug("{}: \t {}\t{}\n", iter, lsr.getValueAtNext(), lsr.getFuncChangeRate());
         }
       }
       if (isConverged(lsr))
@@ -294,7 +293,7 @@ public double[] minimize(Function function) {
 
     long endTime = System.currentTimeMillis();
     long duration = endTime - startTime;
-    logger.info("Running time: " + (duration / 1000.) + "s\n");
+    logger.info("Running time: {}s\n", (duration / 1000.));
 
     // Release memory
     this.updateInfo = null;

opennlp-tools/src/main/java/opennlp/tools/ml/naivebayes/NaiveBayesTrainer.java

@@ -233,7 +233,7 @@ private double trainingStats(EvalParameters evalParams) {
       }
     }
     double trainingAccuracy = (double) numCorrect / numEvents;
-    logger.info("Stats: (" + numCorrect + "/" + numEvents + ") " + trainingAccuracy);
+    logger.info("Stats: ({}/{}) {}", numCorrect, numEvents, trainingAccuracy);
     return trainingAccuracy;
   }
 

opennlp-tools/src/main/java/opennlp/tools/ml/perceptron/PerceptronTrainer.java

@@ -288,7 +288,7 @@ public AbstractModel trainModel(int iterations, DataIndexer di, int cutoff, bool
 
   private MutableContext[] findParameters(int iterations, boolean useAverage) {
 
-    logger.info("Performing " + iterations + " iterations.");
+    logger.info("Performing {} iterations.", iterations);
 
     int[] allOutcomesPattern = new int[numOutcomes];
     for (int oi = 0; oi < numOutcomes; oi++)
@@ -373,7 +373,7 @@ private MutableContext[] findParameters(int iterations, boolean useAverage) {
       // Calculate the training accuracy and display.
       double trainingAccuracy = (double) numCorrect / numEvents;
       if (i < 10 || (i % 10) == 0)
-        logger.info("{}: (" + numCorrect + "/" + numEvents + ") " + trainingAccuracy, i);
+        logger.info("{}: ({}/{}) {}", i, numCorrect, numEvents, trainingAccuracy);
 
       // TODO: Make averaging configurable !!!
 
@@ -442,7 +442,7 @@ private double trainingStats(EvalParameters evalParams) {
       }
     }
     double trainingAccuracy = (double) numCorrect / numEvents;
-    logger.info("Stats: (" + numCorrect + "/" + numEvents + ") " + trainingAccuracy);
+    logger.info("Stats: ({}/{}) {}", numCorrect, numEvents, trainingAccuracy);
     return trainingAccuracy;
   }
 

opennlp-tools/src/main/java/opennlp/tools/ml/perceptron/SimplePerceptronSequenceTrainer.java

@@ -253,7 +253,7 @@ public AbstractModel trainModel(int iterations, SequenceStream<Event> sequenceSt
   }
 
   private void findParameters(int iterations) throws IOException {
-    logger.info("Performing " + iterations + " iterations.\n");
+    logger.info("Performing {} iterations.\n", iterations);
     for (int i = 1; i <= iterations; i++) {
       nextIteration(i);
     }
@@ -356,23 +356,22 @@ public void nextIteration(int iteration) throws IOException {
             int pi = pmap.getOrDefault(feature, -1);
             if (pi != -1) {
               if (logger.isTraceEnabled()) {
-                logger.trace(si + " " + outcomeLabels[oi] + " " + feature + " "
-                    + featureCounts.get(oi).get(feature));
+                logger.trace("{} {} {} {}",
+                    si, outcomeLabels[oi], feature, featureCounts.get(oi).get(feature));
               }
               params[pi].updateParameter(oi, featureCounts.get(oi).get(feature));
               if (useAverage) {
                 if (updates[pi][oi][VALUE] != 0) {
                   averageParams[pi].updateParameter(oi, updates[pi][oi][VALUE] * (numSequences
                       * (iteration - updates[pi][oi][ITER]) + (si - updates[pi][oi][EVENT])));
                   if (logger.isTraceEnabled()) {
-                    logger.trace("p avp[" + pi + "]." + oi + "=" + averageParams[pi].getParameters()[oi]);
+                    logger.trace("p avp[{}].{}={}", pi, oi, averageParams[pi].getParameters()[oi]);
                   }
                 }
                 if (logger.isTraceEnabled()) {
-                  logger.trace("p updates[" + pi + "][" + oi + "]=(" + updates[pi][oi][ITER] + ","
-                      + updates[pi][oi][EVENT] + "," + updates[pi][oi][VALUE] + ") + ("
-                      + iteration + "," + oei + "," + params[pi].getParameters()[oi]
-                      + ") -> " + averageParams[pi].getParameters()[oi]);
+                  logger.trace("p updates[{}]{{}]=({},{},{})({},{},{}) -> {}", pi, oi, updates[pi][oi][ITER],
+                      updates[pi][oi][EVENT], updates[pi][oi][VALUE], iteration, oei,
+                      params[pi].getParameters()[oi], averageParams[pi].getParameters()[oi]);
                 }
                 updates[pi][oi][VALUE] = (int) params[pi].getParameters()[oi];
                 updates[pi][oi][ITER] = iteration;
@@ -399,16 +398,16 @@ public void nextIteration(int iteration) throws IOException {
             predParams[oi] /= totIterations;
             averageParams[pi].setParameter(oi, predParams[oi]);
             if (logger.isTraceEnabled()) {
-              logger.trace("updates[" + pi + "][" + oi + "]=(" + updates[pi][oi][ITER] + ","
-                  + updates[pi][oi][EVENT] + "," + updates[pi][oi][VALUE] + ") + (" + iterations
-                  + "," + 0 + "," + params[pi].getParameters()[oi] + ") -> "
-                  + averageParams[pi].getParameters()[oi]);
+              logger.trace("updates[{}][{}]=({},{},{})({},{},{}) -> {}", pi, oi, updates[pi][oi][ITER],
+                  updates[pi][oi][EVENT], updates[pi][oi][VALUE], iterations, 0,
+                  params[pi].getParameters()[oi], averageParams[pi].getParameters()[oi]);
             }
           }
         }
       }
     }
-    logger.info("{}. (" + numCorrect + "/" + numEvents + ") " + ((double) numCorrect / numEvents), iteration);
+    logger.info("{}. ({}/{}) {}", iteration, numCorrect,
+        numEvents, ((double) numCorrect / numEvents));
   }
 
   private void trainingStats(MutableContext[] params) throws IOException {
@@ -428,6 +427,6 @@ private void trainingStats(MutableContext[] params) throws IOException {
         }
       }
     }
-    logger.info(". (" + numCorrect + "/" + numEvents + ") " + ((double) numCorrect / numEvents));
+    logger.info(". ({}/{}) {}", numCorrect, numEvents, ((double) numCorrect / numEvents));
   }
 }

opennlp-tools/src/main/java/opennlp/tools/parser/AbstractBottomUpParser.java

@@ -295,7 +295,7 @@ public Parse[] parse(Parse tokens, int numParses) {
           guess = tp;
         }
         if (logger.isDebugEnabled()) {
-          logger.debug(derivationStage + " " + derivationRank + " " + tp.getProb());
+          logger.debug("{} {} {}", derivationStage, derivationRank, tp.getProb());
           tp.show();
         }
         Parse[] nd;

opennlp-tools/src/main/java/opennlp/tools/parser/Parse.java

@@ -323,8 +323,8 @@ public void insert(final Parse constituent) {
       for (; pi < pn; pi++) {
         Parse subPart = parts.get(pi);
         if (logger.isTraceEnabled()) {
-          logger.trace("Parse.insert:con=" + constituent + " sp[" + pi + "] "
-              + subPart + " " + subPart.getType());
+          logger.trace("Parse.insert:con={} sp[{}] {} {}",
+              constituent, pi, subPart, subPart.getType());
         }
         Span sp = subPart.span;
         if (sp.getStart() >= ic.getEnd()) {
@@ -340,7 +340,8 @@ else if (ic.contains(sp)) {
           constituent.parts.add(subPart);
           subPart.setParent(constituent);
           if (logger.isTraceEnabled()) {
-            logger.trace("Parse.insert: " + subPart.hashCode() + " -> " + subPart.getParent().hashCode());
+            logger.trace("Parse.insert: {} -> {}",
+                subPart.hashCode(), subPart.getParent().hashCode());
           }
           pn = parts.size();
         } else if (sp.contains(ic)) {
@@ -352,7 +353,7 @@ else if (ic.contains(sp)) {
         }
       }
       if (logger.isTraceEnabled()) {
-        logger.trace("Parse.insert:adding con=" + constituent + " to " + this);
+        logger.trace("Parse.insert:adding con={} to {}", constituent, this);
       }
       parts.add(pi, constituent);
       constituent.setParent(this);
@@ -375,20 +376,20 @@ public void show(StringBuffer sb) {
       sb.append("(");
       sb.append(type).append(" ");
       if (logger.isTraceEnabled()) {
-        logger.trace(label + " ");
+        logger.trace("{} ", label);
       }
       if (logger.isTraceEnabled()) {
-        logger.trace(head + " ");
+        logger.trace("{} ", head);
       }
       if (logger.isTraceEnabled()) {
-        logger.trace(prob + " ");
+        logger.trace("{} ", prob);
       }
     }
     for (Parse c : parts) {
       Span s = c.span;
       if (start < s.getStart()) {
         if (logger.isTraceEnabled()) {
-          logger.trace("pre " + start + " " + s.getStart());
+          logger.trace("pre {} {}", start, s.getStart());
         }
         sb.append(encodeToken(text.substring(start, s.getStart())));
       }
@@ -418,11 +419,11 @@ public void show() {
    */
   public double getTagSequenceProb() {
     if (logger.isTraceEnabled()) {
-      logger.trace("Parse.getTagSequenceProb: " + type + " " + this);
+      logger.trace("Parse.getTagSequenceProb: {} {}",type, this);
     }
     if (parts.size() == 1 && (parts.get(0)).type.equals(AbstractBottomUpParser.TOK_NODE)) {
       if (logger.isTraceEnabled()) {
-        logger.trace(this + " " + prob);
+        logger.trace("{} {}", this, prob);
       }
       return (StrictMath.log(prob));
     } else if (parts.size() == 0) {
@@ -582,7 +583,7 @@ public Parse adjoin(Parse sister, HeadRules rules) {
   public void expandTopNode(Parse root) {
     boolean beforeRoot = true;
     if (logger.isTraceEnabled()) {
-      logger.trace("expandTopNode: parts=" + parts);
+      logger.trace("expandTopNode: parts={}", parts);
     }
     for (int pi = 0, ai = 0; pi < parts.size(); pi++, ai++) {
       Parse node = parts.get(pi);
@@ -839,7 +840,7 @@ public static Parse parseParse(String parse, GapLabeler gl) {
         if (token != null) {
           if (Objects.equals(type, "-NONE-") && gl != null) {
             if (logger.isTraceEnabled()) {
-              logger.trace("stack.size=" + stack.size());
+              logger.trace("stack.size={}", stack.size());
             }
             gl.labelGaps(stack);
           } else {
@@ -868,7 +869,7 @@ public static Parse parseParse(String parse, GapLabeler gl) {
         }
         Parse c = new Parse(txt, con.getSpan(), type, 1, tokenIndex);
         if (logger.isTraceEnabled()) {
-          logger.trace("insert[" + tokenIndex + "] " + type + " " + c + " " + c.hashCode());
+          logger.trace("insert[{}] {} {} {}", tokenIndex, type, c, c.hashCode());
         }
         p.insert(c);
         //codeTree(p);
@@ -1064,7 +1065,7 @@ public static void addNames(String tag, Span[] names, Parse[] tokens) {
       Parse endToken = tokens[nameTokenSpan.getEnd() - 1];
       Parse commonParent = startToken.getCommonParent(endToken);
       if (logger.isTraceEnabled()) {
-        logger.trace("addNames: " + startToken + " .. " + endToken + " commonParent = " + commonParent);
+        logger.trace("addNames: {} .. {} commonParent = {}", startToken, endToken, commonParent);
       }
       if (commonParent != null) {
         Span nameSpan = new Span(startToken.getSpan().getStart(), endToken.getSpan().getEnd());