Repository: incubator-ratis Updated Branches: refs/heads/master 55fffd96b -> 5e3269bb2
RATIS-230. Improve gRPC log messages. Project: http://git-wip-us.apache.org/repos/asf/incubator-ratis/repo Commit: http://git-wip-us.apache.org/repos/asf/incubator-ratis/commit/5e3269bb Tree: http://git-wip-us.apache.org/repos/asf/incubator-ratis/tree/5e3269bb Diff: http://git-wip-us.apache.org/repos/asf/incubator-ratis/diff/5e3269bb Branch: refs/heads/master Commit: 5e3269bb2c0d95b011097ad71124a2d2796739fc Parents: 55fffd9 Author: Tsz Sze <[email protected]> Authored: Wed Apr 25 10:47:02 2018 -0700 Committer: Tsz Sze <[email protected]> Committed: Wed Apr 25 10:47:02 2018 -0700 ---------------------------------------------------------------------- .../java/org/apache/ratis/util/LogUtils.java | 11 +++++++++++ .../org/apache/ratis/grpc/RaftGrpcUtil.java | 20 ++++++++++++++++++-- .../grpc/client/RaftClientProtocolService.java | 6 ++++-- .../ratis/grpc/server/GRpcLogAppender.java | 5 +---- .../grpc/server/RaftServerProtocolService.java | 15 +++++---------- 5 files changed, 39 insertions(+), 18 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/incubator-ratis/blob/5e3269bb/ratis-common/src/main/java/org/apache/ratis/util/LogUtils.java ---------------------------------------------------------------------- diff --git a/ratis-common/src/main/java/org/apache/ratis/util/LogUtils.java b/ratis-common/src/main/java/org/apache/ratis/util/LogUtils.java index 376fed5..280aaab 100644 --- a/ratis-common/src/main/java/org/apache/ratis/util/LogUtils.java +++ b/ratis-common/src/main/java/org/apache/ratis/util/LogUtils.java @@ -127,4 +127,15 @@ public interface LogUtils { } }; } + + static void warn(Logger log, Supplier<String> message, Throwable t, Class<?>... exceptionClasses) { + if (log.isWarnEnabled()) { + if (ReflectionUtils.isInstance(t, exceptionClasses)) { + // do not print stack trace for known exceptions. + log.warn(message.get() + ": " + t); + } else { + log.warn(message.get(), t); + } + } + } } http://git-wip-us.apache.org/repos/asf/incubator-ratis/blob/5e3269bb/ratis-grpc/src/main/java/org/apache/ratis/grpc/RaftGrpcUtil.java ---------------------------------------------------------------------- diff --git a/ratis-grpc/src/main/java/org/apache/ratis/grpc/RaftGrpcUtil.java b/ratis-grpc/src/main/java/org/apache/ratis/grpc/RaftGrpcUtil.java index bad7a07..ecbbf44 100644 --- a/ratis-grpc/src/main/java/org/apache/ratis/grpc/RaftGrpcUtil.java +++ b/ratis-grpc/src/main/java/org/apache/ratis/grpc/RaftGrpcUtil.java @@ -18,15 +18,18 @@ package org.apache.ratis.grpc; import org.apache.ratis.protocol.RaftClientReply; +import org.apache.ratis.protocol.ServerNotReadyException; import org.apache.ratis.shaded.io.grpc.Metadata; import org.apache.ratis.shaded.io.grpc.Status; import org.apache.ratis.shaded.io.grpc.StatusRuntimeException; import org.apache.ratis.shaded.io.grpc.stub.StreamObserver; import org.apache.ratis.util.*; +import org.slf4j.Logger; import java.io.IOException; import java.util.concurrent.CompletableFuture; import java.util.function.Function; +import java.util.function.Supplier; public interface RaftGrpcUtil { Metadata.Key<String> EXCEPTION_TYPE_KEY = @@ -52,12 +55,20 @@ public interface RaftGrpcUtil { static Throwable unwrapThrowable(Throwable t) { if (t instanceof StatusRuntimeException) { - return unwrapException((StatusRuntimeException)t); + final IOException ioe = tryUnwrapException((StatusRuntimeException)t); + if (ioe != null) { + return ioe; + } } return t; } static IOException unwrapException(StatusRuntimeException se) { + final IOException ioe = tryUnwrapException(se); + return ioe != null? ioe: new IOException(se); + } + + static IOException tryUnwrapException(StatusRuntimeException se) { final Metadata trailers = se.getTrailers(); final Status status = se.getStatus(); if (trailers != null && status != null) { @@ -69,11 +80,12 @@ public interface RaftGrpcUtil { clazz.asSubclass(Exception.class), status.getDescription(), se); return IOUtils.asIOException(unwrapped); } catch (Exception e) { + se.addSuppressed(e); return new IOException(se); } } } - return new IOException(se); + return null; } static long getCallId(Throwable t) { @@ -112,4 +124,8 @@ public interface RaftGrpcUtil { responseObserver.onError(RaftGrpcUtil.wrapException(e)); } } + + static void warn(Logger log, Supplier<String> message, Throwable t) { + LogUtils.warn(log, message, unwrapThrowable(t), StatusRuntimeException.class, ServerNotReadyException.class); + } } http://git-wip-us.apache.org/repos/asf/incubator-ratis/blob/5e3269bb/ratis-grpc/src/main/java/org/apache/ratis/grpc/client/RaftClientProtocolService.java ---------------------------------------------------------------------- diff --git a/ratis-grpc/src/main/java/org/apache/ratis/grpc/client/RaftClientProtocolService.java b/ratis-grpc/src/main/java/org/apache/ratis/grpc/client/RaftClientProtocolService.java index 8517bf8..4b92be5 100644 --- a/ratis-grpc/src/main/java/org/apache/ratis/grpc/client/RaftClientProtocolService.java +++ b/ratis-grpc/src/main/java/org/apache/ratis/grpc/client/RaftClientProtocolService.java @@ -162,7 +162,7 @@ public class RaftClientProtocolService extends RaftClientProtocolServiceImplBase @Override public void onError(Throwable t) { // for now we just log a msg - LOG.warn(name + ": onError", t); + RaftGrpcUtil.warn(LOG, () -> name + ": onError", t); slidingWindow.close(); } @@ -184,7 +184,9 @@ public class RaftClientProtocolService extends RaftClientProtocolServiceImplBase void responseError(Throwable t, Supplier<String> message) { if (isClosed.compareAndSet(false, true)) { t = JavaUtils.unwrapCompletionException(t); - LOG.debug(name + ": Failed " + message.get(), t); + if (LOG.isDebugEnabled()) { + LOG.debug(name + ": Failed " + message.get(), t); + } responseObserver.onError(RaftGrpcUtil.wrapException(t)); slidingWindow.close(); } http://git-wip-us.apache.org/repos/asf/incubator-ratis/blob/5e3269bb/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/GRpcLogAppender.java ---------------------------------------------------------------------- diff --git a/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/GRpcLogAppender.java b/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/GRpcLogAppender.java index 2c52aa0..d69a897 100644 --- a/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/GRpcLogAppender.java +++ b/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/GRpcLogAppender.java @@ -238,10 +238,7 @@ public class GRpcLogAppender extends LogAppender { LOG.info("{} is stopped", GRpcLogAppender.this); return; } - if (LOG.isWarnEnabled()) { - LOG.warn("{} got error when appending entries to {}, exception: {}.", - server.getId(), follower.getPeer().getId(), RaftGrpcUtil.unwrapThrowable(t)); - } + RaftGrpcUtil.warn(LOG, () -> server.getId() + ": Failed appendEntries to " + follower.getPeer().getId(), t); long callId = RaftGrpcUtil.getCallId(t); synchronized (this) { http://git-wip-us.apache.org/repos/asf/incubator-ratis/blob/5e3269bb/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/RaftServerProtocolService.java ---------------------------------------------------------------------- diff --git a/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/RaftServerProtocolService.java b/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/RaftServerProtocolService.java index e61b64b..d047803 100644 --- a/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/RaftServerProtocolService.java +++ b/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/RaftServerProtocolService.java @@ -55,8 +55,7 @@ public class RaftServerProtocolService extends RaftServerProtocolServiceImplBase responseObserver.onNext(reply); responseObserver.onCompleted(); } catch (Throwable e) { - LOG.info("{} got exception when handling requestVote {}: {}", - getId(), request.getServerRequest(), e); + RaftGrpcUtil.warn(LOG, () -> getId() + ": Failed requestVote " + ProtoUtils.toString(request.getServerRequest()), e); responseObserver.onError(RaftGrpcUtil.wrapException(e)); } } @@ -83,10 +82,7 @@ public class RaftServerProtocolService extends RaftServerProtocolServiceImplBase return null; }); } catch (Throwable e) { - if (LOG.isDebugEnabled()) { - LOG.debug("{} got exception when appendEntries {}: {}", - getId(), ProtoUtils.toString(request.getServerRequest()), e); - } + RaftGrpcUtil.warn(LOG, () -> getId() + ": Failed appendEntries " + ProtoUtils.toString(request.getServerRequest()), e); responseObserver.onError(RaftGrpcUtil.wrapException(e, request.getServerRequest().getCallId())); current.completeExceptionally(e); } @@ -95,7 +91,7 @@ public class RaftServerProtocolService extends RaftServerProtocolServiceImplBase @Override public void onError(Throwable t) { // for now we just log a msg - LOG.info("{}: appendEntries on error. Exception: {}", getId(), t); + RaftGrpcUtil.warn(LOG, () -> getId() + ": appendEntries onError", t); } @Override @@ -118,15 +114,14 @@ public class RaftServerProtocolService extends RaftServerProtocolServiceImplBase final InstallSnapshotReplyProto reply = server.installSnapshot(request); responseObserver.onNext(reply); } catch (Throwable e) { - LOG.info("{} got exception when handling installSnapshot {}: {}", - getId(), request.getServerRequest(), e); + RaftGrpcUtil.warn(LOG, () -> getId() + ": Failed installSnapshot " + ProtoUtils.toString(request.getServerRequest()), e); responseObserver.onError(RaftGrpcUtil.wrapException(e)); } } @Override public void onError(Throwable t) { - LOG.info("{}: installSnapshot on error. Exception: {}", getId(), t); + RaftGrpcUtil.warn(LOG, () -> getId() + ": installSnapshot onError", t); } @Override
