aurora-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From zma...@apache.org
Subject aurora git commit: Improve scheduling throughput via logging changes.
Date Fri, 02 Dec 2016 22:13:23 GMT
Repository: aurora
Updated Branches:
  refs/heads/master 3ea0331d4 -> 4bc524614


Improve scheduling throughput via logging changes.

This patch makes two logging performance changes.

First, it reduces the cost of logging by replacing the costly class and line
patterns with the cheaper logger pattern. We lose line numbers and inner class
information for much cheaper logging.

Before
````
I1201 15:08:40.560 [AsyncProcessor-0, StateMachine$Builder:389] SchedulerLifecycle state machine
transition LEADER_AWAITING_REGISTRATION -> ACTIVE
````

After
````
I1201 15:06:47.181 [AsyncProcessor-0, StateMachine] SchedulerLifecycle state machine transition
LEADER_AWAITING_REGISTRATION -> ACTIVE
````

Second, it reduces the verbosity of the `TaskStateMachine` logging where it logs
the work command from the transition. I don't think there is any operator value
in logging this (unlike the task state transitions) so I have lowered it to
debug.

Performance Before:

````
Benchmark                                               (numPendingTasks)  (numTasksToDelete)
  Mode  Cnt  Score   Error  Units
StateManagerBenchmarks.DeleteTasksBenchmark.run                       N/A                1000
 thrpt   10  2.510 ± 0.557  ops/s
StateManagerBenchmarks.DeleteTasksBenchmark.run                       N/A               10000
 thrpt   10  0.272 ± 0.030  ops/s
StateManagerBenchmarks.DeleteTasksBenchmark.run                       N/A               50000
 thrpt   10  0.053 ± 0.011  ops/s
StateManagerBenchmarks.InsertPendingTasksBenchmark.run               1000                
N/A  thrpt   10  2.446 ± 0.698  ops/s
StateManagerBenchmarks.InsertPendingTasksBenchmark.run              10000                
N/A  thrpt   10  0.246 ± 0.018  ops/s
StateManagerBenchmarks.InsertPendingTasksBenchmark.run              50000                
N/A  thrpt   10  0.041 ± 0.006  ops/s
````

Performance After:
````
Benchmark                                               (numPendingTasks)  (numTasksToDelete)
  Mode  Cnt   Score   Error  Units
StateManagerBenchmarks.DeleteTasksBenchmark.run                       N/A                1000
 thrpt   10  14.520 ± 5.696  ops/s
StateManagerBenchmarks.DeleteTasksBenchmark.run                       N/A               10000
 thrpt   10   1.290 ± 0.361  ops/s
StateManagerBenchmarks.DeleteTasksBenchmark.run                       N/A               50000
 thrpt   10   0.254 ± 0.097  ops/s
StateManagerBenchmarks.InsertPendingTasksBenchmark.run               1000                
N/A  thrpt    5   7.303 ± 5.662  ops/s
StateManagerBenchmarks.InsertPendingTasksBenchmark.run              10000                
N/A  thrpt    5   0.726 ± 0.624  ops/s
StateManagerBenchmarks.InsertPendingTasksBenchmark.run              50000                
N/A  thrpt    5   0.124 ± 0.058  ops/s
````

There is a performance improvement in the smaller case and no noticable
degredation in the larger cases. I also verified on a small cluster that the
improvements exist for the larger cases. I am unable to reduce the error bars
locally on the `InsertPendingTasksBenchmark`. I suspect the bencmark needs to be
tweaked to be more consistent.

Bugs closed: AURORA-1831

Reviewed at https://reviews.apache.org/r/54269/


Project: http://git-wip-us.apache.org/repos/asf/aurora/repo
Commit: http://git-wip-us.apache.org/repos/asf/aurora/commit/4bc52461
Tree: http://git-wip-us.apache.org/repos/asf/aurora/tree/4bc52461
Diff: http://git-wip-us.apache.org/repos/asf/aurora/diff/4bc52461

Branch: refs/heads/master
Commit: 4bc5246149f296b14dc520bedd71747fdb2578fb
Parents: 3ea0331
Author: Zameer Manji <zmanji@apache.org>
Authored: Fri Dec 2 14:13:08 2016 -0800
Committer: Zameer Manji <zmanji@apache.org>
Committed: Fri Dec 2 14:13:08 2016 -0800

----------------------------------------------------------------------
 RELEASE-NOTES.md                                                | 2 ++
 .../org/apache/aurora/scheduler/state/TaskStateMachine.java     | 2 +-
 src/main/resources/logback.xml                                  | 5 ++++-
 3 files changed, 7 insertions(+), 2 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/aurora/blob/4bc52461/RELEASE-NOTES.md
----------------------------------------------------------------------
diff --git a/RELEASE-NOTES.md b/RELEASE-NOTES.md
index 7a3d331..90c4793 100644
--- a/RELEASE-NOTES.md
+++ b/RELEASE-NOTES.md
@@ -20,6 +20,8 @@
   can now rely purely on health checks rather than `watch_secs` timeout when deciding an
individial
   instance update state, by setting `watch_secs` to 0. A service will remain in `STARTING`
state
   util `min_consecutive_successes` consecutive health checks have passed.
+- The default logging output has been changed to remove line numbers and inner class information
in
+  exchange for faster logging.
 
 ### Deprecations and removals:
 

http://git-wip-us.apache.org/repos/asf/aurora/blob/4bc52461/src/main/java/org/apache/aurora/scheduler/state/TaskStateMachine.java
----------------------------------------------------------------------
diff --git a/src/main/java/org/apache/aurora/scheduler/state/TaskStateMachine.java b/src/main/java/org/apache/aurora/scheduler/state/TaskStateMachine.java
index 23f256a..eb4fe7d 100644
--- a/src/main/java/org/apache/aurora/scheduler/state/TaskStateMachine.java
+++ b/src/main/java/org/apache/aurora/scheduler/state/TaskStateMachine.java
@@ -471,7 +471,7 @@ class TaskStateMachine {
   }
 
   private void addFollowup(SideEffect sideEffect) {
-    LOG.info("Adding work command " + sideEffect + " for " + this);
+    LOG.debug("Adding work command {} for {}", sideEffect, this);
     sideEffects.add(sideEffect);
   }
 

http://git-wip-us.apache.org/repos/asf/aurora/blob/4bc52461/src/main/resources/logback.xml
----------------------------------------------------------------------
diff --git a/src/main/resources/logback.xml b/src/main/resources/logback.xml
index 84c175c..f4a8fa1 100644
--- a/src/main/resources/logback.xml
+++ b/src/main/resources/logback.xml
@@ -22,8 +22,11 @@ limitations under the License.
   <appender name="STDERR" class="ch.qos.logback.core.ConsoleAppender">
     <target>System.err</target>
     <encoder>
+      <!-- Before changing this, consult http://logback.qos.ch/manual/layouts.html and
make sure
+      the parameter is not expensive. Once changed, run benchmarks to ensure that throughput
is
+      the same !-->
       <pattern>
-        %.-1level%date{MMdd HH:mm:ss.SSS} [%thread, %class{0}:%line] %message %xThrowable%n
+        %.-1level%date{MMdd HH:mm:ss.SSS} [%thread, %logger{0}] %message %xThrowable%n
       </pattern>
     </encoder>
   </appender>


Mime
View raw message