SOLR-3157: restrict changes to logging string to formatter

git-svn-id: https://svn.apache.org/repos/asf/lucene/dev/trunk@1294967 13f79535-47bb-0310-9956-ffa450edef68

solr/core/src/java/org/apache/solr/SolrLogFormatter.java

@@ -54,17 +54,33 @@ public class SolrLogFormatter extends Formatter {
       return className + '.' + methodName;
     }
   }
-  
-  
 
-  
-  protected SolrLogFormatter() {
+
+  public SolrLogFormatter() {
     super();
     
     methodAlias.put(new Method("org.apache.solr.update.processor.LogUpdateProcessor","finish"), "UPDATE");
     methodAlias.put(new Method("org.apache.solr.core.SolrCore","execute"), "REQ");
   }
 
+
+  // TODO: name this better... it's only for cloud tests where every core container has just one solr server so Port/Core are fine
+  public boolean shorterFormat = false;
+
+  /**  Removes info that is redundant for current cloud tests including core name, webapp, and common labels path= and params=
+   * [] webapp=/solr path=/select params={q=foobarbaz} hits=0 status=0 QTime=1
+   * /select {q=foobarbaz} hits=0 status=0 QTime=1
+   * NOTE: this is a work in progress and different settings may be ideal for other types of tests.
+   */
+  public void setShorterFormat() {
+    shorterFormat = true;
+    // looking at /update is enough... we don't need "UPDATE /update"
+    methodAlias.put(new Method("org.apache.solr.update.processor.LogUpdateProcessor","finish"), "");
+  }
+
+
+
+
   public static class CoreInfo {
     public static int maxCoreNum;
     public String shortId;
@@ -188,10 +204,13 @@ sb.append("(group_name=").append(tg.getName()).append(")");
       sb.append(' ').append(info.shortId);                     // core
     }
     if (zkController != null) {
-      sb.append(" P").append(zkController.getHostPort());
+      sb.append(" P").append(zkController.getHostPort());      // todo: should be able to get this from core container for non zk tests
+    }
+
+    if (shortClassName.length() > 0) {
+      sb.append(' ').append(shortClassName);
     }
 
-    sb.append(' ').append(shortClassName);
     if (record.getLevel() != Level.INFO) {
       sb.append(' ').append(record.getLevel());
     }
@@ -254,20 +273,62 @@ sb.append("(group_name=").append(tg.getName()).append(")");
     return sb.toString() + '.' + method;
   }
   
+  private void addFirstLine(StringBuilder sb, String msg) {
+//    INFO: [] webapp=/solr path=/select params={q=foobarbaz} hits=0 status=0 QTime=1
+
+    if (!shorterFormat || !msg.startsWith("[")) {
+      sb.append(msg);      
+      return;
+    }
+
+    int idx = msg.indexOf(']');
+    if (idx < 0 || !msg.startsWith(" webapp=", idx+1)) {
+      sb.append(msg);
+      return;
+    }
+    
+    idx = msg.indexOf(' ',idx+8); // space after webapp=
+    if (idx < 0) { sb.append(msg); return; }
+    idx = msg.indexOf('=',idx+1);   // = in  path=
+    if (idx < 0) { sb.append(msg); return; }
+
+    int idx2 = msg.indexOf(' ',idx+1);
+    if (idx2 < 0) { sb.append(msg); return; }
+
+
+    sb.append(msg.substring(idx+1, idx2+1));  // path
+    
+    idx = msg.indexOf("params=", idx2);
+    if (idx < 0) {
+      sb.append(msg.substring(idx2));
+    } else {
+      sb.append(msg.substring(idx+7));
+    }
+  }
+  
   private void appendMultiLineString(StringBuilder sb, String msg) {
     int idx = msg.indexOf('\n');
     if (idx < 0) {
-      sb.append(msg);
+      addFirstLine(sb, msg);
       return;
     }
 
     int lastIdx = -1;
     for (;;) {
       if (idx < 0) {
-        sb.append(msg.substring(lastIdx+1));
+        if (lastIdx == -1) {
+          addFirstLine(sb, msg.substring(lastIdx+1));
+        } else {
+          sb.append(msg.substring(lastIdx+1));
+        }
         break;
       }
-      sb.append(msg.substring(lastIdx+1, idx));
+      if (lastIdx == -1) {
+        addFirstLine(sb, msg.substring(lastIdx+1, idx));
+      } else {
+        sb.append(msg.substring(lastIdx+1, idx));
+      }
+
       sb.append("\n\t");
       lastIdx = idx;
       idx = msg.indexOf('\n',lastIdx+1);
@@ -352,7 +413,7 @@ sb.append("(group_name=").append(tg.getName()).append(")");
       @Override
       public void run() {
         threadLocal.set("from thread1");
-        log.error("InThread1");
+        log.error("[] webapp=/solr path=/select params={hello} wow");
       }
     };
 

solr/core/src/java/org/apache/solr/core/SolrCore.java

@@ -1536,17 +1536,15 @@ public final class SolrCore implements SolrInfoMBean {
     // for back compat, we set these now just in case other code
     // are expecting them during handleRequest
 
-    if (!isTestLoggingFormat) {
-      toLog.add("webapp", req.getContext().get("webapp"));
-    }
-    toLog.add(isTestLoggingFormat ? null : "path", req.getContext().get("path"));
-    toLog.add(isTestLoggingFormat ? null : "params", "{" + req.getParamString() + "}");
+    toLog.add("webapp", req.getContext().get("webapp"));
+    toLog.add("path", req.getContext().get("path"));
+    toLog.add("params", "{" + req.getParamString() + "}");
 
     handler.handleRequest(req,rsp);
     setResponseHeaderValues(handler,req,rsp);
 
     if (log.isInfoEnabled() && toLog.size() > 0) {
-      StringBuilder sb = new StringBuilder();
+      StringBuilder sb = new StringBuilder(logid);
       for (int i=0; i<toLog.size(); i++) {
         String name = toLog.getName(i);
         Object val = toLog.getVal(i);

solr/core/src/java/org/apache/solr/update/processor/LogUpdateProcessorFactory.java

@@ -181,7 +181,7 @@ class LogUpdateProcessor extends UpdateRequestProcessor {
 
     NamedList<Object> stdLog = rsp.getToLog();
 
-    StringBuilder sb = new StringBuilder();
+    StringBuilder sb = new StringBuilder(req.getCore().getLogId());
 
     for (int i=0; i<stdLog.size(); i++) {
       String name = stdLog.getName(i);

solr/core/src/test/org/apache/solr/cloud/FullSolrCloudTest.java

@@ -60,7 +60,12 @@ import org.junit.Ignore;
  */
 @Ignore
 public class FullSolrCloudTest extends AbstractDistributedZkTestCase {
-  
+  @BeforeClass
+  public static void beforeFullSolrCloudTest() throws Exception {
+    // shorten the log output more for this test type
+    if (formatter != null) formatter.setShorterFormat();
+  }
+
   private static final String SHARD2 = "shard2";
   
   private boolean printLayoutOnTearDown = false;

solr/test-framework/src/java/org/apache/solr/SolrTestCaseJ4.java

@@ -43,6 +43,7 @@ import org.apache.solr.schema.SchemaField;
 import org.apache.solr.search.SolrIndexSearcher;
 import org.apache.solr.servlet.DirectSolrConnection;
 import org.apache.solr.util.TestHarness;
+import org.apache.zookeeper.server.LogFormatter;
 import org.junit.AfterClass;
 import org.junit.BeforeClass;
 import org.slf4j.Logger;
@@ -97,6 +98,7 @@ public abstract class SolrTestCaseJ4 extends LuceneTestCase {
     super.tearDown();
   }
 
+  public static SolrLogFormatter formatter;
 
   public static void setupLogging() {
     SolrCore.isTestLoggingFormat = true;
@@ -116,7 +118,8 @@ public abstract class SolrTestCaseJ4 extends LuceneTestCase {
     }
 
     consoleHandler.setLevel(Level.ALL);
-    consoleHandler.setFormatter(new SolrLogFormatter());
+    formatter = new SolrLogFormatter();
+    consoleHandler.setFormatter(formatter);
 
     if (register) {
       java.util.logging.Logger.getLogger("").addHandler(consoleHandler);