core: don't reschedule idle timer if it is already active #4297

carl-mastrangelo · 2018-04-03T15:36:51Z

I haven't quite got the tests to pass yet but I think this is close enough for review to take a look. The main idea is to avoid rescheduling the IdleModeTimer if it is already active. This has pretty good results on my machine for the latency benchmarks. With CPU freq scaling on, median latency goes from 197us to 185us. (no TLS, but with census enabled, direct executor).

The changes to get the tests to work are going to be harder since this change depends on System.nanoTime. The FakeClock we use in our tests doesn't make it easy to mock this out, so I'm working on ideas to fix this. That said, it is starting to get invasive for tests to pass.

Raw numbers from my runs:

Before (w/freq scaling)
50.0%ile Latency (in nanos):		197071
90.0%ile Latency (in nanos):		253383
95.0%ile Latency (in nanos):		272479
99.0%ile Latency (in nanos):		318191
99.9%ile Latency (in nanos):		411519
100.0%ile Latency (in nanos):		16083967
QPS:                           5005


After:
50.0%ile Latency (in nanos):		185023
90.0%ile Latency (in nanos):		240671
95.0%ile Latency (in nanos):		259319
99.0%ile Latency (in nanos):		299887
99.9%ile Latency (in nanos):		379855
100.0%ile Latency (in nanos):		11492351
QPS:                           5320

Before (w/o freq scaling)

50.0%ile Latency (in nanos):		63907
90.0%ile Latency (in nanos):		73055
95.0%ile Latency (in nanos):		79443
99.0%ile Latency (in nanos):		93739
99.9%ile Latency (in nanos):		123583
100.0%ile Latency (in nanos):		14028287
QPS:                           14936

After:
After:
50.0%ile Latency (in nanos):		57355
90.0%ile Latency (in nanos):		69459
95.0%ile Latency (in nanos):		78495
99.0%ile Latency (in nanos):		93575
99.9%ile Latency (in nanos):		126819
100.0%ile Latency (in nanos):		12634111
QPS:                           16435

carl-mastrangelo · 2018-04-03T15:40:11Z

core/src/main/java/io/grpc/internal/ManagedChannelImpl.java

+    }
+
+    /** Time source representing nanoseconds since fixed but arbitrary point in time. */
+    interface Ticker {


FYI: Guava's ticker is an abstract class, and marked @Beta. I can't use it here, so I define an interface.

I toyed with this some (just now) using Stopwatch. I think it ends up fine (no unnecessary now() calls in the normal paths), and it is a stable API.

Switched to using stopwatch.

zhangkun83

Overall looks good with minor comments.

zhangkun83 · 2018-04-03T23:30:58Z

core/src/main/java/io/grpc/internal/KeepAliveManager.java

@@ -293,7 +293,7 @@ public void onPingTimeout() {
    public abstract long read();
  }

-  private static class SystemTicker extends Ticker {
+  static class SystemTicker extends Ticker {


Why this change?

Reverted, this was originally going to be reused.

zhangkun83 · 2018-04-04T17:01:25Z

core/src/main/java/io/grpc/internal/ManagedChannelImpl.java

+    private long runAt;
+    private boolean enabled;
+
+    Rescheduler(Runnable r, ChannelExecutor exec, ScheduledExecutorService scheduler) {


There is a way to decouple Rescheduler from ChannelExecutor. Pass an Executor here and make it an requirement that it must serialize its runnables and rechedule(). In ManagedChannelImpl, you could make an Executor that delegates to ChannelExecutor. I am strong for splitting this class out of ManagedChannelImpl, which is good for test-ability and also for the fitness of ManagedChannelImpl.

carl-mastrangelo

PTAL

carl-mastrangelo · 2018-04-04T20:55:53Z

core/src/main/java/io/grpc/internal/ManagedChannelImpl.java

+    private long runAt;
+    private boolean enabled;
+
+    Rescheduler(Runnable r, ChannelExecutor exec, ScheduledExecutorService scheduler) {


carl-mastrangelo · 2018-04-04T20:56:06Z

core/src/main/java/io/grpc/internal/ManagedChannelImpl.java

+    }
+
+    /** Time source representing nanoseconds since fixed but arbitrary point in time. */
+    interface Ticker {


Switched to using stopwatch.

carl-mastrangelo · 2018-04-04T20:56:24Z

core/src/main/java/io/grpc/internal/KeepAliveManager.java

@@ -293,7 +293,7 @@ public void onPingTimeout() {
    public abstract long read();
  }

-  private static class SystemTicker extends Ticker {
+  static class SystemTicker extends Ticker {


Reverted, this was originally going to be reused.

ejona86

Please still wait for @zhangkun83's review.

ejona86 · 2018-04-04T21:41:09Z

core/src/test/java/io/grpc/internal/FakeClock.java

@@ -317,4 +317,4 @@ public long currentTimeMillis() {
     */
    boolean shouldAccept(Runnable runnable);
  }
-}
+}


Revert changes to this file?

ejona86 · 2018-04-04T21:43:27Z

core/src/main/java/io/grpc/internal/Rescheduler.java

+    return ((FutureRunnable) r).rescheduler.enabled;
+  }
+
+  private long nanoTime() {


I see what you did there. 😄

ejona86 · 2018-04-04T21:45:51Z

core/src/main/java/io/grpc/internal/Rescheduler.java

+    }
+  }
+
+  private static final class FutureRunnable implements Runnable {


nit: Why is this static?

In ManagedChannelImplIdlenessTest.java there is a test that checks there are no more scheduled tasks in the scheduler. It fails because the tasks are still left over, but now disabled. I wanted to make it so the test scans the tasks and checks to see they are Rescheduler Runnables, and that they are disabled.

There needs to be a reference from the Runnable back to the Rescheduler, so this became static and took an explicit reference to the outer class. This is so isEnabled below works.

Ah, I see. You could have added another method to FutureRunnable to do something like return Rescheduler.this, but that's close to the same amount of effort. Makes sense.

zhangkun83 · 2018-04-04T22:20:06Z

core/src/test/java/io/grpc/internal/ReschedulerTest.java

+    assertFalse(runner.ran);
+    rescheduler.reschedule(1, TimeUnit.NANOSECONDS);
+    assertFalse(runner.ran);
+    rescheduler.cancel(/* permanent= */ false);


You probably need a test for cancel(true)

zhangkun83 · 2018-04-04T22:22:19Z

core/src/test/java/io/grpc/internal/ReschedulerTest.java

+    rescheduler.reschedule(1, TimeUnit.NANOSECONDS);
+    assertFalse(runner.ran);
+    assertFalse(exec.executed);
+    rescheduler.reschedule(50, TimeUnit.NANOSECONDS);


Since you are keeping the flexibility of rescheduling with a shorter delay, you should cover it, or remove the flexibility.

don't reschedule idle timer if it is already active

fab86d7

carl-mastrangelo requested review from zhangkun83 and ejona86 April 3, 2018 15:37

carl-mastrangelo commented Apr 3, 2018

View reviewed changes

use wakeup rather than enabled

aa18a5b

zhangkun83 reviewed Apr 4, 2018

View reviewed changes

carl-mastrangelo added 3 commits April 4, 2018 13:35

made tests pass

1056b90

ad dtetss

4ba2ebf

revert

3d2d972

carl-mastrangelo commented Apr 4, 2018

View reviewed changes

ejona86 approved these changes Apr 4, 2018

View reviewed changes

revert formatting changes

3a85717

zhangkun83 reviewed Apr 4, 2018

View reviewed changes

more tests

626f41b

zhangkun83 approved these changes Apr 4, 2018

View reviewed changes

carl-mastrangelo merged commit 9ed8425 into grpc:master Apr 4, 2018

carl-mastrangelo deleted the resched branch April 4, 2018 23:02

lock bot locked as resolved and limited conversation to collaborators Jan 18, 2019

carl-mastrangelo restored the resched branch August 17, 2019 01:12

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

core: don't reschedule idle timer if it is already active #4297

core: don't reschedule idle timer if it is already active #4297

carl-mastrangelo commented Apr 3, 2018

carl-mastrangelo Apr 3, 2018

ejona86 Apr 3, 2018 •

edited

Loading

carl-mastrangelo Apr 4, 2018

zhangkun83 left a comment

zhangkun83 Apr 3, 2018

carl-mastrangelo Apr 4, 2018

zhangkun83 Apr 4, 2018

carl-mastrangelo Apr 4, 2018

carl-mastrangelo left a comment

carl-mastrangelo Apr 4, 2018

carl-mastrangelo Apr 4, 2018

carl-mastrangelo Apr 4, 2018

ejona86 left a comment

ejona86 Apr 4, 2018

carl-mastrangelo Apr 4, 2018

ejona86 Apr 4, 2018

ejona86 Apr 4, 2018

carl-mastrangelo Apr 4, 2018

ejona86 Apr 4, 2018

zhangkun83 Apr 4, 2018

carl-mastrangelo Apr 4, 2018

zhangkun83 Apr 4, 2018

carl-mastrangelo Apr 4, 2018

core: don't reschedule idle timer if it is already active #4297

core: don't reschedule idle timer if it is already active #4297

Conversation

carl-mastrangelo commented Apr 3, 2018

Choose a reason for hiding this comment

ejona86 Apr 3, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zhangkun83 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

carl-mastrangelo 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

ejona86 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

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

ejona86 Apr 3, 2018 •

edited

Loading