ScheduledExecutorService won't log the exception if the task throws

[zhangkun83]

Unlike Executor.execute(), which lets the thread's default exception handler to log anything thrown from the task, ScheduledExecutorService.schedule() expects you to get the exceptions from the returned ScheduledFuture, and will not log the exceptions.

As we want to log everything thrown from inside the executors, and don't want to check the ScheduledFuture each time we use ScheduledExecutorService, we probably need to create our own ScheduledExecutorService that logs the exceptions and avoid using the vanilla version.

[carl-mastrangelo]

I've taken a look at this, and there are some questions that need to be answered before moving forward:

• Should we be logging if the executor used is provided from the user? Would it be presumptuous to log everything the grpc code submits to the executor?
• Several places use the future that comes back from the executor if it is a service of some kind. Should we still log if we know the error is propagated by someone calling .get() on the future?
• It would be possible to make a special Executor that overrides execute (as oppose to submit) and check if the submitted runnables are FutureTask's. In this way we could determine which runnables are likely Futures and which are not handled. This adds extra overhead, and might not be desired.

One other thing: UncaughtExceptionHandler works on a per thread, not a per executor level. ThreadPoolExecutor and ScheduledThreadPoolExecutor do not let exceptions propagate far enough to reach the handler.

[ejona86]

Should we be logging if the executor used is provided from the user? Would it be presumptuous to log everything the grpc code submits to the executor?

Yes, I think we should log in this case. It could be presumptuous, but we only have a few callsites that call schedule. And in fact, I don't think we allow users to provide the ScheduledExecutorService anyway.

Several places use the future that comes back from the executor if it is a service of some kind. Should we still log if we know the error is propagated by someone calling .get() on the future?

Really? No, I don't think we should necessary log in that case, but we should make sure that someone is handling the error. I don't actually know anywhere the future.get() is being called.

It would be possible to make a special Executor that overrides execute (as oppose to submit) and check if the submitted runnables are FutureTask's. In this way we could determine which runnables are likely Futures and which are not handled. This adds extra overhead, and might not be desired.

But how does that solve the problem? When execute calls runnable.run() the runnable won't throw if it is a FutureTask. Instead we need to handle it by whatever is passed to schedule because that code handles exceptions before FutureTask does.

ThreadPoolExecutor and ScheduledThreadPoolExecutor do not let exceptions propagate far enough to reach the handler.

It seems like they do, and in fact goes a little out of its way:
http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/8u40-b25/java/util/concurrent/ThreadPoolExecutor.java/#1127

It ends up letting the thread die and UncaughtExceptionHandler process the exception, and then it creates a new thread for further processing.

[carl-mastrangelo]

I ran the following test to check the behavior before writing this:

  @Test
  public void maintest() throws Exception {
    ExecutorService e = Executors.newCachedThreadPool(new ThreadFactoryBuilder()
        .setUncaughtExceptionHandler(new UncaughtExceptionHandler() {
          @Override
          public void uncaughtException(Thread t, Throwable e) {
            System.err.println(String.format("Bad %s %s", t, t));
          }
        })
        .build());
    e.submit(new Runnable() {
      @Override
      public void run() {
        System.err.println("BANG!");
        throw new RuntimeException();
      }
    });
    e.shutdown();
    e.awaitTermination(100, TimeUnit.SECONDS);
  }

It only prints out "BANG!"

[ejona86]

@carl-mastrangelo, why do we care about submit()? git grep '\.submit(' didn't show any calls to it.

execute() itself is fine, as using it instead of submit() prints out:

BANG!
Bad Thread[pool-1-thread-1,5,main] Thread[pool-1-thread-1,5,main]

Although I do believe ScheduledExecutorService.execute behaves differently (and is fairly harmful in its behavior). Right now I don't care if exceptions are swallowed in that case.

Primarily only need to worry about schedule(). If someone calls schedule(), then it is wrapped in a FutureTask and queued directly (bypassing execute()). We either need to override schedule() to wrap the Runnable, or we need to handle exceptions directly within the Runnable itself.