core: don't reschedule idle timer if it is already active by carl-mastrangelo · Pull Request #4297 · grpc/grpc-java

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

+    }
+
+    /** 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

  }

-  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

+    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

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


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

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


Switched to using stopwatch.

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

  }

-  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

    boolean shouldAccept(Runnable runnable);
  }
-}
+}


Revert changes to this file?

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

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


I see what you did there. 😄

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

+    }
+  }
+
+  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

+    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

+    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 ejona86 and zhangkun83 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

Conversation

carl-mastrangelo commented Apr 3, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

ejona86 Apr 3, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

zhangkun83 left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

carl-mastrangelo left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

ejona86 left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

ejona86 Apr 3, 2018 •

edited

Loading