SOLR-7902: Split out use of child timers from RTimer to a sub-class

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

solr/CHANGES.txt

@@ -145,6 +145,9 @@ Other Changes
   even after all local replicas of that collection have been removed.
   (Scott Blum via shalin)
 
+* SOLR-7902: Split out use of child timers from RTimer to a sub-class
+  (Ramkumar Aiyengar)
+
 ==================  5.3.0 ==================
 
 Consult the LUCENE_CHANGES.txt file for additional, low level, changes in this release

solr/core/src/java/org/apache/solr/handler/component/SearchHandler.java

@@ -35,7 +35,6 @@ import org.apache.solr.common.params.ModifiableSolrParams;
 import org.apache.solr.common.params.ShardParams;
 import org.apache.solr.common.util.NamedList;
 import org.apache.solr.common.util.SimpleOrderedMap;
-import org.apache.solr.common.util.StrUtils;
 import org.apache.solr.core.CloseHook;
 import org.apache.solr.core.PluginInfo;
 import org.apache.solr.core.SolrCore;
@@ -44,7 +43,7 @@ import org.apache.solr.request.SolrQueryRequest;
 import org.apache.solr.response.SolrQueryResponse;
 import org.apache.solr.search.SolrQueryTimeoutImpl;
 import org.apache.solr.search.facet.FacetModule;
-import org.apache.solr.util.RTimer;
+import org.apache.solr.util.RTimerTree;
 import org.apache.solr.util.SolrPluginUtils;
 import org.apache.solr.util.plugin.PluginInfoInitialized;
 import org.apache.solr.util.plugin.SolrCoreAware;
@@ -241,7 +240,7 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware ,
       SolrPluginUtils.getDebugInterests(req.getParams().getParams(CommonParams.DEBUG), rb);
     }
 
-    final RTimer timer = rb.isDebug() ? req.getRequestTimer() : null;
+    final RTimerTree timer = rb.isDebug() ? req.getRequestTimer() : null;
 
     final ShardHandler shardHandler1 = getAndPrepShardHandler(req, rb); // creates a ShardHandler object only if it's needed
     
@@ -252,7 +251,7 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware ,
       }
     } else {
       // debugging prepare phase
-      RTimer subt = timer.sub( "prepare" );
+      RTimerTree subt = timer.sub( "prepare" );
       for( SearchComponent c : components ) {
         rb.setTimer( subt.sub( c.getName() ) );
         c.prepare(rb);
@@ -279,7 +278,7 @@ public class SearchHandler extends RequestHandlerBase implements SolrCoreAware ,
         }
         else {
           // Process
-          RTimer subt = timer.sub( "process" );
+          RTimerTree subt = timer.sub( "process" );
           for( SearchComponent c : components ) {
             rb.setTimer( subt.sub( c.getName() ) );
             c.process(rb);

solr/core/src/java/org/apache/solr/request/SolrQueryRequest.java

@@ -17,13 +17,12 @@
 
 package org.apache.solr.request;
 
-import org.apache.solr.response.SolrQueryResponse;
 import org.apache.solr.search.SolrIndexSearcher;
 import org.apache.solr.schema.IndexSchema;
-import org.apache.solr.util.RTimer;
 import org.apache.solr.common.params.SolrParams;
 import org.apache.solr.common.util.ContentStream;
 import org.apache.solr.core.SolrCore;
+import org.apache.solr.util.RTimerTree;
 
 import java.security.Principal;
 import java.util.Map;
@@ -72,7 +71,7 @@ public interface SolrQueryRequest {
   public long getStartTime();
 
   /** The timer for this request, created when the request started being processed */
-  public RTimer getRequestTimer();
+  public RTimerTree getRequestTimer();
 
   /** The index searcher associated with this request */
   public SolrIndexSearcher getSearcher();

solr/core/src/java/org/apache/solr/request/SolrQueryRequestBase.java

@@ -18,9 +18,8 @@
 package org.apache.solr.request;
 
 import org.apache.solr.common.util.SuppressForbidden;
-import org.apache.solr.response.SolrQueryResponse;
 import org.apache.solr.search.SolrIndexSearcher;
-import org.apache.solr.util.RTimer;
+import org.apache.solr.util.RTimerTree;
 import org.apache.solr.util.RefCounted;
 import org.apache.solr.schema.IndexSchema;
 import org.apache.solr.common.params.SolrParams;
@@ -54,11 +53,11 @@ public abstract class SolrQueryRequestBase implements SolrQueryRequest, Closeabl
   protected Iterable<ContentStream> streams;
   protected Map<String,Object> json;
 
-  private final RTimer requestTimer;
+  private final RTimerTree requestTimer;
   protected final long startTime;
 
   @SuppressForbidden(reason = "Need currentTimeMillis to get start time for request (to be used for stats/debugging)")
-  public SolrQueryRequestBase(SolrCore core, SolrParams params, RTimer requestTimer) {
+  public SolrQueryRequestBase(SolrCore core, SolrParams params, RTimerTree requestTimer) {
     this.core = core;
     this.schema = null == core ? null : core.getLatestSchema();
     this.params = this.origParams = params;
@@ -67,7 +66,7 @@ public abstract class SolrQueryRequestBase implements SolrQueryRequest, Closeabl
   }
 
   public SolrQueryRequestBase(SolrCore core, SolrParams params) {
-    this(core, params, new RTimer());
+    this(core, params, new RTimerTree());
   }
 
   @Override
@@ -99,7 +98,8 @@ public abstract class SolrQueryRequestBase implements SolrQueryRequest, Closeabl
     return startTime;
   }
 
-  public RTimer getRequestTimer () {
+  @Override
+  public RTimerTree getRequestTimer () {
     return requestTimer;
   }
 

solr/core/src/java/org/apache/solr/servlet/HttpSolrCall.java

@@ -1,38 +1,5 @@
 package org.apache.solr.servlet;
 
-import static org.apache.solr.common.cloud.ZkStateReader.BASE_URL_PROP;
-import static org.apache.solr.common.cloud.ZkStateReader.COLLECTION_PROP;
-import static org.apache.solr.common.cloud.ZkStateReader.CORE_NAME_PROP;
-import static org.apache.solr.common.cloud.ZkStateReader.NODE_NAME_PROP;
-import static org.apache.solr.common.params.CollectionParams.CollectionAction.CREATE;
-import static org.apache.solr.common.params.CollectionParams.CollectionAction.DELETE;
-import static org.apache.solr.common.params.CollectionParams.CollectionAction.RELOAD;
-import static org.apache.solr.servlet.SolrDispatchFilter.Action.ADMIN;
-import static org.apache.solr.servlet.SolrDispatchFilter.Action.FORWARD;
-import static org.apache.solr.servlet.SolrDispatchFilter.Action.PASSTHROUGH;
-import static org.apache.solr.servlet.SolrDispatchFilter.Action.PROCESS;
-import static org.apache.solr.servlet.SolrDispatchFilter.Action.REMOTEQUERY;
-import static org.apache.solr.servlet.SolrDispatchFilter.Action.RETRY;
-import static org.apache.solr.servlet.SolrDispatchFilter.Action.RETURN;
-
-import java.io.EOFException;
-import java.io.IOException;
-import java.io.InputStream;
-import java.io.OutputStream;
-import java.io.UnsupportedEncodingException;
-import java.security.Principal;
-import java.util.ArrayList;
-import java.util.Collection;
-import java.util.Collections;
-import java.util.Enumeration;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.Iterator;
-import java.util.List;
-import java.util.Map;
-import java.util.Random;
-import java.util.Set;
-
 /*
  * Licensed to the Apache Software Foundation (ASF) under one or more
  * contributor license agreements.  See the NOTICE file distributed with
@@ -50,9 +17,25 @@ import java.util.Set;
  * limitations under the License.
  */
 
-
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
+import java.io.EOFException;
+import java.io.IOException;
+import java.io.InputStream;
+import java.io.OutputStream;
+import java.io.UnsupportedEncodingException;
+import java.security.Principal;
+import java.util.ArrayList;
+import java.util.Collection;
+import java.util.Collections;
+import java.util.Enumeration;
+import java.util.HashMap;
+import java.util.HashSet;
+import java.util.Iterator;
+import java.util.List;
+import java.util.Map;
+import java.util.Random;
+import java.util.Set;
 
 import org.apache.commons.io.IOUtils;
 import org.apache.commons.lang.StringUtils;
@@ -110,11 +93,26 @@ import org.apache.solr.servlet.SolrDispatchFilter.Action;
 import org.apache.solr.servlet.cache.HttpCacheHeaderUtil;
 import org.apache.solr.servlet.cache.Method;
 import org.apache.solr.update.processor.DistributingUpdateProcessorFactory;
-import org.apache.solr.util.RTimer;
+import org.apache.solr.util.RTimerTree;
 import org.apache.zookeeper.KeeperException;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import static org.apache.solr.common.cloud.ZkStateReader.BASE_URL_PROP;
+import static org.apache.solr.common.cloud.ZkStateReader.COLLECTION_PROP;
+import static org.apache.solr.common.cloud.ZkStateReader.CORE_NAME_PROP;
+import static org.apache.solr.common.cloud.ZkStateReader.NODE_NAME_PROP;
+import static org.apache.solr.common.params.CollectionParams.CollectionAction.CREATE;
+import static org.apache.solr.common.params.CollectionParams.CollectionAction.DELETE;
+import static org.apache.solr.common.params.CollectionParams.CollectionAction.RELOAD;
+import static org.apache.solr.servlet.SolrDispatchFilter.Action.ADMIN;
+import static org.apache.solr.servlet.SolrDispatchFilter.Action.FORWARD;
+import static org.apache.solr.servlet.SolrDispatchFilter.Action.PASSTHROUGH;
+import static org.apache.solr.servlet.SolrDispatchFilter.Action.PROCESS;
+import static org.apache.solr.servlet.SolrDispatchFilter.Action.REMOTEQUERY;
+import static org.apache.solr.servlet.SolrDispatchFilter.Action.RETRY;
+import static org.apache.solr.servlet.SolrDispatchFilter.Action.RETURN;
+
 /**
  * This class represents a call made to Solr
  **/
@@ -195,7 +193,7 @@ public class HttpSolrCall {
     String corename = "";
     String origCorename = null;
     // set a request timer which can be reused by requests if needed
-    req.setAttribute(SolrRequestParsers.REQUEST_TIMER_SERVLET_ATTRIBUTE, new RTimer());
+    req.setAttribute(SolrRequestParsers.REQUEST_TIMER_SERVLET_ATTRIBUTE, new RTimerTree());
     // put the core container in request attribute
     req.setAttribute("org.apache.solr.CoreContainer", cores);
     path = req.getServletPath();

solr/core/src/java/org/apache/solr/servlet/SolrRequestParsers.java

@@ -57,6 +57,7 @@ import org.apache.solr.core.SolrCore;
 import org.apache.solr.request.SolrQueryRequest;
 import org.apache.solr.request.SolrQueryRequestBase;
 import org.apache.solr.util.RTimer;
+import org.apache.solr.util.RTimerTree;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
@@ -140,14 +141,14 @@ public class SolrRequestParsers
     parsers.put( "", standard );
   }
 
-  private static RTimer getRequestTimer(HttpServletRequest req)
+  private static RTimerTree getRequestTimer(HttpServletRequest req)
   {
     final Object reqTimer = req.getAttribute(REQUEST_TIMER_SERVLET_ATTRIBUTE);
-    if (reqTimer != null && reqTimer instanceof RTimer) {
+    if (reqTimer != null && reqTimer instanceof RTimerTree) {
-      return ((RTimer) reqTimer);
+      return ((RTimerTree) reqTimer);
     }
 
-    return new RTimer();
+    return new RTimerTree();
   }
 
   public SolrQueryRequest parse( SolrCore core, String path, HttpServletRequest req ) throws Exception
@@ -173,11 +174,11 @@ public class SolrRequestParsers
   }
 
   public SolrQueryRequest buildRequestFrom(SolrCore core, SolrParams params, Collection<ContentStream> streams) throws Exception {
-    return buildRequestFrom(core, params, streams, new RTimer(), null);
+    return buildRequestFrom(core, params, streams, new RTimerTree(), null);
   }
 
   private SolrQueryRequest buildRequestFrom(SolrCore core, SolrParams params, Collection<ContentStream> streams,
-                                            RTimer requestTimer, final HttpServletRequest req) throws Exception {
+                                            RTimerTree requestTimer, final HttpServletRequest req) throws Exception {
     // The content type will be applied to all streaming content
     String contentType = params.get( CommonParams.STREAM_CONTENTTYPE );
       

solr/core/src/java/org/apache/solr/util/RTimer.java

@@ -17,16 +17,11 @@ package org.apache.solr.util;
  * limitations under the License.
  */
 
-import java.util.Map;
 import java.util.concurrent.TimeUnit;
 
-import org.apache.solr.common.util.NamedList;
+/** A simple timer.
-import org.apache.solr.common.util.SimpleOrderedMap;
-
-/** A recursive timer.
  * 
- * RTimers are started automatically when instantiated; subtimers are also
+ * RTimers are started automatically when instantiated.
- * started automatically when created.
  *
  * @since solr 1.3
  *
@@ -38,10 +33,9 @@ public class RTimer {
   public static final int PAUSED = 2;
 
   protected int state;
-  protected TimerImpl timerImpl;
+  private TimerImpl timerImpl;
-  protected double time;
+  private double time;
-  protected double culmTime;
+  private double culmTime;
-  protected SimpleOrderedMap<RTimer> children;
 
   protected interface TimerImpl {
     void start();
@@ -62,32 +56,21 @@ public class RTimer {
     return new NanoTimeTimerImpl();
   }
 
-  protected RTimer newTimer() {
-    return new RTimer();
-  }
-
   public RTimer() {
     time = 0;
     culmTime = 0;
-    children = new SimpleOrderedMap<>();
     timerImpl = newTimerImpl();
     timerImpl.start();
     state = STARTED;
   }
 
-  /** Recursively stop timer and sub timers */
+  /** Stop this timer */
   public double stop() {
     assert state == STARTED || state == PAUSED;
     time = culmTime;
     if(state == STARTED) 
       time += timerImpl.elapsed();
     state = STOPPED;
-    
-    for( Map.Entry<String,RTimer> entry : children ) {
-      RTimer child = entry.getValue();
-      if(child.state == STARTED || child.state == PAUSED) 
-        child.stop();
-    }
     return time;
   }
 
@@ -114,41 +97,4 @@ public class RTimer {
       return culmTime + timerImpl.elapsed();
     }
  }
-
-  /** Create new subtimer with given name
-   *
-   * Subtimer will be started.
-   */
-  public RTimer sub(String desc) {
-    RTimer child = children.get( desc );
-    if( child == null ) {
-      child = newTimer();
-      children.add(desc, child);
-    }
-    return child;
-  }
-
-  @Override
-  public String toString() {
-    return asNamedList().toString();
-  }
-
-  public NamedList asNamedList() {
-    NamedList<Object> m = new SimpleOrderedMap<>();
-    m.add( "time", getTime() );
-    if( children.size() > 0 ) {
-      for( Map.Entry<String, RTimer> entry : children ) {
-        m.add( entry.getKey(), entry.getValue().asNamedList() );
-      }
-    }
-    return m;
-  }
-  
-  /**
-   * Manipulating this map may have undefined results.
-   */
-  public SimpleOrderedMap<RTimer> getChildren()
-  {
-    return children;
-  }
 }

solr/core/src/java/org/apache/solr/util/RTimerTree.java

@@ -0,0 +1,91 @@
+package org.apache.solr.util;
+
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License.  You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+import java.util.Map;
+
+import org.apache.solr.common.util.NamedList;
+import org.apache.solr.common.util.SimpleOrderedMap;
+
+/** A recursive timer.
+ *
+ * RTimerTree's are started automatically when instantiated; sub-timers are also
+ * started automatically when created.
+ */
+public class RTimerTree extends RTimer {
+
+  protected SimpleOrderedMap<RTimerTree> children;
+
+  public RTimerTree() {
+    children = new SimpleOrderedMap<>();
+  }
+
+  /** Recursively stop timer and sub timers */
+  @Override
+  public double stop() {
+    double time = super.stop();
+
+    for( Map.Entry<String,RTimerTree> entry : children ) {
+      RTimer child = entry.getValue();
+      if(child.state == STARTED || child.state == PAUSED)
+        child.stop();
+    }
+    return time;
+  }
+
+  protected RTimerTree newTimer() {
+    return new RTimerTree();
+  }
+
+  /** Create new subtimer with given name
+   *
+   * Subtimer will be started.
+   */
+  public RTimerTree sub(String desc) {
+    RTimerTree child = children.get( desc );
+    if( child == null ) {
+      child = newTimer();
+      children.add(desc, child);
+    }
+    return child;
+  }
+
+  @Override
+  public String toString() {
+    return asNamedList().toString();
+  }
+
+  public NamedList asNamedList() {
+    NamedList<Object> m = new SimpleOrderedMap<>();
+    m.add( "time", getTime() );
+    if( children.size() > 0 ) {
+      for( Map.Entry<String, RTimerTree> entry : children ) {
+        m.add( entry.getKey(), entry.getValue().asNamedList() );
+      }
+    }
+    return m;
+  }
+
+  /**
+   * Manipulating this map may have undefined results.
+   */
+  public SimpleOrderedMap<RTimerTree> getChildren()
+  {
+    return children;
+  }
+}

solr/core/src/test/org/apache/solr/util/TestRTimerTree.java

@@ -20,7 +20,7 @@ package org.apache.solr.util;
 import org.apache.lucene.util.LuceneTestCase;
 import org.apache.solr.common.util.NamedList;
 
-public class TestRTimer extends LuceneTestCase {
+public class TestRTimerTree extends LuceneTestCase {
 
   private static class MockTimerImpl implements RTimer.TimerImpl {
     static private long systemTime;
@@ -37,19 +37,19 @@ public class TestRTimer extends LuceneTestCase {
     }
   }
 
-  private class MockRTimer extends RTimer {
+  private class MockRTimerTree extends RTimerTree {
     @Override
     protected TimerImpl newTimerImpl() {
       return new MockTimerImpl();
     }
     @Override
-    protected RTimer newTimer() {
+    protected RTimerTree newTimer() {
-      return new MockRTimer();
+      return new MockRTimerTree();
     }
   }
 
   public void test() {
-    RTimer rt = new MockRTimer(), subt, st;
+    RTimerTree rt = new MockRTimerTree(), subt, st;
 
     MockTimerImpl.incrementSystemTime(100);
     assertEquals(100, (int) rt.getTime());