diff --git a/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamClient.java b/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamClient.java index 5ec41c055fbd..3ddc8115e7a8 100644 --- a/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamClient.java +++ b/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamClient.java @@ -18,22 +18,24 @@ import io.grpc.ManagedChannel; import io.grpc.ManagedChannelBuilder; +import io.grpc.Status; import io.grpc.examples.manualflowcontrol.StreamingGreeterGrpc; import io.grpc.stub.ClientCallStreamObserver; import io.grpc.stub.ClientResponseObserver; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import java.util.Arrays; import java.util.Iterator; import java.util.List; import java.util.concurrent.CountDownLatch; import java.util.concurrent.TimeUnit; -import java.util.logging.Logger; /** * @author Taejin Koo */ public class HelloWorldStreamClient { - private final Logger logger = Logger.getLogger(HelloWorldStreamClient.class.getName()); + private final Logger logger = LogManager.getLogger(HelloWorldStreamClient.class); private final ManagedChannel channel; private final StreamingGreeterGrpc.StreamingGreeterStub stub; @@ -125,7 +127,8 @@ public void onNext(io.grpc.examples.manualflowcontrol.HelloReply value) { @Override public void onError(Throwable t) { - t.printStackTrace(); + Status status = Status.fromThrowable(t); + logger.info("onError:{}", status); done.countDown(); } diff --git a/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamServer.java b/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamServer.java index d531a716dfc5..95dc593e9102 100644 --- a/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamServer.java +++ b/agent-module/agent-testweb/grpc-plugin-testweb/src/main/java/com/pinpoint/test/plugin/HelloWorldStreamServer.java @@ -129,7 +129,8 @@ public void onNext(HelloRequest request) { @Override public void onError(Throwable t) { // End the response stream if the client presents an error. - t.printStackTrace(); + Status status = Status.fromThrowable(t); + logger.info("onError:{}", status); responseObserver.onCompleted(); } diff --git a/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java b/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java index ddaff77a1b64..dd5c6ac88ea6 100644 --- a/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java +++ b/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java @@ -19,6 +19,7 @@ import com.navercorp.pinpoint.it.plugin.utils.ExecutorUtils; import io.grpc.ManagedChannel; import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.examples.manualflowcontrol.HelloReply; import io.grpc.examples.manualflowcontrol.HelloRequest; import io.grpc.examples.manualflowcontrol.StreamingGreeterGrpc; @@ -29,6 +30,8 @@ import io.netty.channel.EventLoopGroup; import io.netty.channel.nio.NioEventLoopGroup; import io.netty.channel.socket.nio.NioSocketChannel; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import java.util.Arrays; import java.util.Iterator; @@ -38,7 +41,6 @@ import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReference; -import java.util.logging.Logger; /** * copy grpc framework @@ -46,7 +48,7 @@ */ public class HelloWorldStreamClient implements HelloWorldClient { - private final Logger logger = Logger.getLogger(this.getClass().getName()); + private final Logger logger = LogManager.getLogger(this.getClass().getName()); private final ManagedChannel channel; private final StreamingGreeterGrpc.StreamingGreeterStub stub; @@ -142,14 +144,15 @@ public void run() { @Override public void onNext(HelloReply value) { - logger.info("<-- " + value.getMessage()); + logger.info("<-- {}", value.getMessage()); // Signal the sender to send one message. requestStream.request(1); } @Override public void onError(Throwable t) { - t.printStackTrace(); + Status status = Status.fromThrowable(t); + logger.info("onError:{}", status); done.countDown(); } diff --git a/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java b/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java index f7b7b1673f66..f88799f8deb1 100644 --- a/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java +++ b/agent-module/plugins-it/google-grpc-it/google-grpc-1-42-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java @@ -30,13 +30,14 @@ import io.netty.channel.socket.nio.NioServerSocketChannel; import jakarta.annotation.PostConstruct; import jakarta.annotation.PreDestroy; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import java.io.IOException; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.logging.Logger; /** * copy grpc framework @@ -44,7 +45,7 @@ */ public class HelloWorldStreamServer implements HelloWorldServer { - private final Logger logger = Logger.getLogger(this.getClass().getName()); + private final Logger logger = LogManager.getLogger(this.getClass().getName()); private int requestCount; @@ -141,7 +142,8 @@ public void onNext(HelloRequest request) { @Override public void onError(Throwable t) { // End the response stream if the client presents an error. - t.printStackTrace(); + Status status = Status.fromThrowable(t); + logger.info("onError:{}", status); responseObserver.onCompleted(); } diff --git a/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java b/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java index e81ec91b42a0..1cb09125d7ab 100644 --- a/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java +++ b/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamClient.java @@ -18,7 +18,7 @@ import com.navercorp.pinpoint.it.plugin.utils.ExecutorUtils; import io.grpc.ManagedChannel; -import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.examples.manualflowcontrol.HelloReply; import io.grpc.examples.manualflowcontrol.HelloRequest; import io.grpc.examples.manualflowcontrol.StreamingGreeterGrpc; @@ -29,6 +29,8 @@ import io.netty.channel.EventLoopGroup; import io.netty.channel.nio.NioEventLoopGroup; import io.netty.channel.socket.nio.NioSocketChannel; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import java.io.IOException; import java.util.Arrays; @@ -39,7 +41,6 @@ import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReference; -import java.util.logging.Logger; /** * copy grpc framework @@ -47,7 +48,7 @@ */ public class HelloWorldStreamClient implements HelloWorldClient { - private final Logger logger = Logger.getLogger(this.getClass().getName()); + private final Logger logger = LogManager.getLogger(this.getClass().getName()); private final ManagedChannel channel; private final StreamingGreeterGrpc.StreamingGreeterStub stub; @@ -74,7 +75,7 @@ private static ManagedChannel newChannel(String host, int port, EventLoopGroup e builder.eventLoopGroup(eventExecutors); builder.channelType(NioSocketChannel.class); - builder.intercept(MetadataUtils.newCaptureMetadataInterceptor(new AtomicReference(), new AtomicReference())); + builder.intercept(MetadataUtils.newCaptureMetadataInterceptor(new AtomicReference<>(), new AtomicReference<>())); return builder.build(); } @@ -143,14 +144,15 @@ public void run() { @Override public void onNext(HelloReply value) { - logger.info("<-- " + value.getMessage()); + logger.info("<-- {}", value.getMessage()); // Signal the sender to send one message. requestStream.request(1); } @Override public void onError(Throwable t) { - t.printStackTrace(); + Status status = Status.fromThrowable(t); + logger.info("onError:{}", status); done.countDown(); } diff --git a/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java b/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java index e4c505812fe0..ce6a30ba0523 100644 --- a/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java +++ b/agent-module/plugins-it/google-grpc-it/google-grpc-1-8-it/src/test/java/com/navercorp/pinpoint/it/plugin/grpc/HelloWorldStreamServer.java @@ -28,6 +28,8 @@ import io.grpc.stub.StreamObserver; import io.netty.channel.nio.NioEventLoopGroup; import io.netty.channel.socket.nio.NioServerSocketChannel; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import javax.annotation.PostConstruct; import javax.annotation.PreDestroy; @@ -36,7 +38,6 @@ import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; -import java.util.logging.Logger; /** * copy grpc framework @@ -44,7 +45,7 @@ */ public class HelloWorldStreamServer implements HelloWorldServer { - private final Logger logger = Logger.getLogger(this.getClass().getName()); + private final Logger logger = LogManager.getLogger(this.getClass().getName()); private int requestCount; @@ -141,7 +142,8 @@ public void onNext(HelloRequest request) { @Override public void onError(Throwable t) { // End the response stream if the client presents an error. - t.printStackTrace(); + Status status = Status.fromThrowable(t); + logger.info("onError:{}", status); responseObserver.onCompleted(); } diff --git a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/EmptyStreamObserver.java b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/EmptyStreamObserver.java index c704103f615a..1c97e2ab8be2 100644 --- a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/EmptyStreamObserver.java +++ b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/EmptyStreamObserver.java @@ -17,6 +17,7 @@ package com.navercorp.pinpoint.profiler.receiver.grpc; import com.google.protobuf.Empty; +import io.grpc.Status; import io.grpc.stub.StreamObserver; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; @@ -35,7 +36,8 @@ public void onNext(Empty value) { @Override public void onError(Throwable t) { - logger.info("onError. message:{}", t.getMessage(), t); + Status status = Status.fromThrowable(t); + logger.info("onError:{}", status); } @Override diff --git a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/GrpcCommandService.java b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/GrpcCommandService.java index 332a07072855..b3d29e32f415 100644 --- a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/GrpcCommandService.java +++ b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/receiver/grpc/GrpcCommandService.java @@ -16,8 +16,6 @@ package com.navercorp.pinpoint.profiler.receiver.grpc; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; import com.navercorp.pinpoint.grpc.client.SupportCommandCodeClientInterceptor; import com.navercorp.pinpoint.grpc.trace.PCmdMessage; import com.navercorp.pinpoint.grpc.trace.PCmdRequest; @@ -26,6 +24,8 @@ import com.navercorp.pinpoint.profiler.sender.grpc.ReconnectExecutor; import com.navercorp.pinpoint.profiler.sender.grpc.Reconnector; import com.navercorp.pinpoint.profiler.sender.grpc.StreamUtils; +import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.stub.ClientCallStreamObserver; import io.grpc.stub.ClientResponseObserver; import org.apache.logging.log4j.LogManager; @@ -140,12 +140,9 @@ public void onNext(PCmdRequest request) { @Override public void onError(Throwable t) { - final StatusError statusError = StatusErrors.throwable(t); - if (statusError.isSimpleError()) { - logger.info("Failed to command stream, cause={}", statusError.getMessage()); - } else { - logger.warn("Failed to command stream, cause={}", statusError.getMessage(), statusError.getThrowable()); - } + Status status = Status.fromThrowable(t); + Metadata metadata = Status.trailersFromThrowable(t); + logger.info("Failed to command stream, {} {}", status, metadata); if (requestStream != null) { requestStream.onError(t); diff --git a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/LogResponseStreamObserver.java b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/LogResponseStreamObserver.java index eeba4460f5ab..a093e9148346 100644 --- a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/LogResponseStreamObserver.java +++ b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/LogResponseStreamObserver.java @@ -18,8 +18,8 @@ import com.google.protobuf.GeneratedMessageV3; import com.google.protobuf.TextFormat; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; +import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.stub.StreamObserver; import org.apache.logging.log4j.Logger; @@ -46,18 +46,10 @@ public void onNext(ResT response) { @Override public void onError(Throwable throwable) { + Status status = Status.fromThrowable(throwable); + Metadata metadata = Status.trailersFromThrowable(throwable); if (logger.isInfoEnabled()) { - final StatusError statusError = StatusErrors.throwable(throwable); - if (statusError.isSimpleError()) { - logger.info("{} Error. requestId={}, cause={}", name, requestId, statusError.getMessage()); - } else { - if (logger.isDebugEnabled()) { - logger.debug("{} Error. requestId={}, cause={}", name, requestId, statusError.getMessage(), statusError.getThrowable()); - } else { - logger.info("{} Error. requestId={}, cause={}", name, requestId, statusError.getMessage()); - } - - } + logger.info("{} Error. requestId={}, {} {}", name, requestId, status, metadata); } } diff --git a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/PingStreamContext.java b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/PingStreamContext.java index 55e4f5be6480..f5c2f67fb37f 100644 --- a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/PingStreamContext.java +++ b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/PingStreamContext.java @@ -17,10 +17,10 @@ package com.navercorp.pinpoint.profiler.sender.grpc; import com.navercorp.pinpoint.grpc.MessageFormatUtils; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; import com.navercorp.pinpoint.grpc.trace.AgentGrpc; import com.navercorp.pinpoint.grpc.trace.PPing; +import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.stub.ClientCallStreamObserver; import io.grpc.stub.ClientResponseObserver; import io.grpc.stub.StreamObserver; @@ -80,12 +80,11 @@ public void onNext(PPing ping) { @Override public void onError(Throwable t) { - final StatusError statusError = StatusErrors.throwable(t); - if (statusError.isSimpleError()) { - logger.info("Failed to ping stream, streamId={}, cause={}", streamId, statusError.getMessage()); - } else { - logger.info("Failed to ping stream, streamId={}, cause={}", streamId, statusError.getMessage(), statusError.getThrowable()); - } + final Status status = Status.fromThrowable(t); + Metadata metadata = Status.trailersFromThrowable(t); + + logger.info("Failed to ping stream, streamId={}, {} {}", streamId, status, metadata); + cancelPingScheduler(); PingStreamContext.this.reconnector.reconnect(); } diff --git a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/ResponseStreamObserver.java b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/ResponseStreamObserver.java index bf4499892a6e..0f3948553030 100644 --- a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/ResponseStreamObserver.java +++ b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/ResponseStreamObserver.java @@ -16,8 +16,8 @@ package com.navercorp.pinpoint.profiler.sender.grpc; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; +import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.stub.ClientCallStreamObserver; import io.grpc.stub.ClientResponseObserver; import org.apache.logging.log4j.LogManager; @@ -65,12 +65,11 @@ public void onNext(ResT value) { @Override public void onError(Throwable t) { - final StatusError statusError = StatusErrors.throwable(t); - if (statusError.isSimpleError()) { - logger.info("Failed to stream, name={}, cause={}", listener, statusError.getMessage()); - } else { - logger.info("Failed to stream, name={}, cause={}", listener, statusError.getMessage(), statusError.getThrowable()); - } + Status status = Status.fromThrowable(t); + Metadata metadata = Status.trailersFromThrowable(t); + + logger.info("Failed to stream, name={}, {} {}", listener, status, metadata); + listener.onError(t); } diff --git a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/RetryResponseStreamObserver.java b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/RetryResponseStreamObserver.java index 475211046500..93b53e1fae3e 100644 --- a/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/RetryResponseStreamObserver.java +++ b/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/sender/grpc/RetryResponseStreamObserver.java @@ -16,15 +16,16 @@ package com.navercorp.pinpoint.profiler.sender.grpc; -import com.google.protobuf.GeneratedMessageV3; -import com.google.protobuf.TextFormat; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; +import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.stub.StreamObserver; import org.apache.logging.log4j.Logger; import java.util.Objects; +import static com.navercorp.pinpoint.grpc.MessageFormatUtils.debugLog; +import static com.navercorp.pinpoint.grpc.MessageFormatUtils.getSimpleClasName; + /** * @author Woonduk Kang(emeroad) */ @@ -46,12 +47,12 @@ public void onNext(ResT response) { if (retryScheduler.isSuccess(response)) { // Success if (logger.isDebugEnabled()) { - logger.debug("Request success. request={}, result={}", logString(message), logString(response)); + logger.debug("Request success. request={}, result={}", debugLog(message), debugLog((response))); } } else { // Retry if (logger.isInfoEnabled()) { - logger.info("Request failed. PResult.getSuccess() is false. request={}, result={}", logString(message), logString(response)); + logger.info("Request failed. PResult.getSuccess() is false. request={}, result={}", debugLog(message), debugLog((response))); } retryScheduler.scheduleNextRetry(message, nextRetryCount()); } @@ -60,11 +61,13 @@ public void onNext(ResT response) { @Override public void onError(Throwable throwable) { - final StatusError statusError = StatusErrors.throwable(throwable); - if (statusError.isSimpleError()) { - logger.info("Error. request={}, cause={}", logString(message), statusError.getMessage()); - } else { - logger.info("Error. request={}, cause={}", logString(message), statusError.getMessage(), statusError.getThrowable()); + final Status status = Status.fromThrowable(throwable); + final Metadata metadata = Status.trailersFromThrowable(throwable); + + if (logger.isDebugEnabled()) { + logger.debug("onError. request={}, {} metadata={}", debugLog(message), status, metadata); + } else if (logger.isInfoEnabled()) { + logger.info("onError. request={}, {} metadata={}", getSimpleClasName(message), status, metadata); } // Retry @@ -79,14 +82,6 @@ private int nextRetryCount() { return retryCount + 1; } - private String logString(Object message) { - if (message == null) { - return "NULL"; - } - if (message instanceof GeneratedMessageV3) { - GeneratedMessageV3 messageV3 = (GeneratedMessageV3) message; - return TextFormat.shortDebugString(messageV3); - } - return message.toString(); - } + + } diff --git a/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/AgentService.java b/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/AgentService.java index cf9c5935187a..69e67480d7bd 100644 --- a/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/AgentService.java +++ b/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/AgentService.java @@ -20,8 +20,6 @@ import com.navercorp.pinpoint.collector.receiver.DispatchHandler; import com.navercorp.pinpoint.common.profiler.logging.ThrottledLogger; import com.navercorp.pinpoint.grpc.MessageFormatUtils; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; import com.navercorp.pinpoint.grpc.server.ServerContext; import com.navercorp.pinpoint.grpc.server.lifecycle.PingEventHandler; import com.navercorp.pinpoint.grpc.trace.AgentGrpc; @@ -35,6 +33,8 @@ import com.navercorp.pinpoint.io.request.Message; import com.navercorp.pinpoint.thrift.io.DefaultTBaseLocator; import io.grpc.Context; +import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.stub.ServerCallStreamObserver; import io.grpc.stub.StreamObserver; import org.apache.logging.log4j.LogManager; @@ -125,11 +125,10 @@ private PPing newPing() { @Override public void onError(Throwable t) { - final StatusError statusError = StatusErrors.throwable(t); - if (statusError.isSimpleError()) { - thLogger.info("Failed to ping stream, id={}, cause={}", id, statusError.getMessage()); - } else { - thLogger.warn("Failed to ping stream, id={}, cause={}", id, statusError.getMessage(), statusError.getThrowable()); + final Status status = Status.fromThrowable(t); + final Metadata metadata = Status.trailersFromThrowable(t); + if (thLogger.isInfoEnabled()) { + thLogger.info("Failed to ping stream, id={}, {} metadata:{}", id, status, metadata); } disconnect(); } diff --git a/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/SpanService.java b/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/SpanService.java index dd39fdff93e8..8317a3907a66 100644 --- a/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/SpanService.java +++ b/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/SpanService.java @@ -20,8 +20,6 @@ import com.google.protobuf.GeneratedMessageV3; import com.navercorp.pinpoint.collector.receiver.DispatchHandler; import com.navercorp.pinpoint.grpc.MessageFormatUtils; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; import com.navercorp.pinpoint.grpc.server.ServerContext; import com.navercorp.pinpoint.grpc.trace.PSpan; import com.navercorp.pinpoint.grpc.trace.PSpanChunk; @@ -34,6 +32,7 @@ import com.navercorp.pinpoint.io.request.Message; import com.navercorp.pinpoint.io.request.ServerRequest; import com.navercorp.pinpoint.thrift.io.DefaultTBaseLocator; +import io.grpc.Metadata; import io.grpc.Status; import io.grpc.StatusException; import io.grpc.StatusRuntimeException; @@ -84,11 +83,10 @@ public void onNext(PSpanMessage spanMessage) { public void onError(Throwable throwable) { com.navercorp.pinpoint.grpc.Header header = ServerContext.getAgentInfo(); - final StatusError statusError = StatusErrors.throwable(throwable); - if (statusError.isSimpleError()) { - logger.info("Failed to span stream, {} cause={}", header, statusError.getMessage(), statusError.getThrowable()); - } else { - logger.warn("Failed to span stream, {} cause={}", header, statusError.getMessage(), statusError.getThrowable()); + Status status = Status.fromThrowable(throwable); + Metadata metadata = Status.trailersFromThrowable(throwable); + if (logger.isInfoEnabled()) { + logger.info("Failed to span stream, {} {} {}", header, status, metadata); } } diff --git a/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/StatService.java b/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/StatService.java index cc275fa515fd..f344104a5c89 100644 --- a/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/StatService.java +++ b/collector/src/main/java/com/navercorp/pinpoint/collector/receiver/grpc/service/StatService.java @@ -16,10 +16,10 @@ package com.navercorp.pinpoint.collector.receiver.grpc.service; +import com.google.protobuf.Empty; +import com.google.protobuf.GeneratedMessageV3; import com.navercorp.pinpoint.collector.receiver.DispatchHandler; import com.navercorp.pinpoint.grpc.MessageFormatUtils; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; import com.navercorp.pinpoint.grpc.server.ServerContext; import com.navercorp.pinpoint.grpc.trace.PAgentStat; import com.navercorp.pinpoint.grpc.trace.PAgentStatBatch; @@ -33,15 +33,13 @@ import com.navercorp.pinpoint.io.request.Message; import com.navercorp.pinpoint.io.request.ServerRequest; import com.navercorp.pinpoint.thrift.io.DefaultTBaseLocator; - -import com.google.protobuf.Empty; -import com.google.protobuf.GeneratedMessageV3; +import io.grpc.Metadata; import io.grpc.Status; import io.grpc.StatusException; import io.grpc.StatusRuntimeException; import io.grpc.stub.StreamObserver; -import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import java.util.HashMap; import java.util.Objects; @@ -88,11 +86,10 @@ public void onNext(PStatMessage statMessage) { @Override public void onError(Throwable throwable) { - final StatusError statusError = StatusErrors.throwable(throwable); - if (statusError.isSimpleError()) { - logger.info("Failed to stat stream, cause={}", statusError.getMessage()); - } else { - logger.warn("Failed to stat stream, cause={}", statusError.getMessage(), statusError.getThrowable()); + Status status = Status.fromThrowable(throwable); + Metadata metadata = Status.trailersFromThrowable(throwable); + if (logger.isInfoEnabled()) { + logger.info("Failed to stat stream, {} {}", status, metadata); } } diff --git a/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/AgentClientMock.java b/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/AgentClientMock.java index 5a0e5a72a10e..576649f535d8 100644 --- a/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/AgentClientMock.java +++ b/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/AgentClientMock.java @@ -157,7 +157,8 @@ public V getValue() { @Override public void onError(Throwable throwable) { - logger.info("Error ", throwable); + Status status = Status.fromThrowable(throwable); + logger.info("onError:{}", status); } @Override diff --git a/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/StatClientMock.java b/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/StatClientMock.java index 96cb98a28c2e..48f99de1cdc4 100644 --- a/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/StatClientMock.java +++ b/collector/src/test/java/com/navercorp/pinpoint/collector/receiver/grpc/StatClientMock.java @@ -27,11 +27,12 @@ import io.grpc.ClientInterceptor; import io.grpc.ManagedChannel; import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.netty.NettyChannelBuilder; import io.grpc.stub.MetadataUtils; import io.grpc.stub.StreamObserver; -import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import java.util.concurrent.TimeUnit; @@ -102,7 +103,8 @@ public void onNext(Empty pResult) { @Override public void onError(Throwable throwable) { - logger.info("Error ", throwable); + Status status = Status.fromThrowable(throwable); + logger.info("onError:{}", status); } @Override diff --git a/grpc/src/main/java/com/navercorp/pinpoint/grpc/MessageFormatUtils.java b/grpc/src/main/java/com/navercorp/pinpoint/grpc/MessageFormatUtils.java index 7bf6b6c62265..28bf65e4f3c2 100644 --- a/grpc/src/main/java/com/navercorp/pinpoint/grpc/MessageFormatUtils.java +++ b/grpc/src/main/java/com/navercorp/pinpoint/grpc/MessageFormatUtils.java @@ -19,6 +19,8 @@ import com.google.protobuf.GeneratedMessageV3; import com.google.protobuf.TextFormat; +import java.util.Objects; + /** * @author jaehong.kim */ @@ -37,6 +39,16 @@ public static LogMessage debugLog(GeneratedMessageV3 message) { return new LazyLogMessage(message); } + public static LogMessage debugLog(Object message) { + if (message == null) { + return NULL_LOG; + } + if (message instanceof GeneratedMessageV3) { + return new LazyLogMessage((GeneratedMessageV3) message); + } + return new LazyLogObject(message); + } + // No need wrapper class // public static String debugString(GeneratedMessageV3 message) { // if (message == null) { @@ -45,6 +57,12 @@ public static LogMessage debugLog(GeneratedMessageV3 message) { // return TextFormat.shortDebugString(message); // } + public static String getSimpleClasName(Object message) { + if (message == null) { + return NULL_STR; + } + return message.getClass().getSimpleName(); + } public interface LogMessage { } @@ -53,7 +71,7 @@ private static class LazyLogMessage implements LogMessage { private final GeneratedMessageV3 message; private LazyLogMessage(final GeneratedMessageV3 message) { - this.message = message; + this.message = Objects.requireNonNull(message, "message"); } @Override @@ -62,6 +80,19 @@ public String toString() { } } + private static class LazyLogObject implements LogMessage { + private final Object message; + + private LazyLogObject(final Object message) { + this.message = Objects.requireNonNull(message, "message"); + } + + @Override + public String toString() { + return message.toString(); + } + } + private static class NullLogMessage implements LogMessage { @Override public String toString() { diff --git a/grpc/src/main/java/com/navercorp/pinpoint/grpc/StatusErrors.java b/grpc/src/main/java/com/navercorp/pinpoint/grpc/StatusErrors.java index 5299ffcfc06a..04f801eae5e7 100644 --- a/grpc/src/main/java/com/navercorp/pinpoint/grpc/StatusErrors.java +++ b/grpc/src/main/java/com/navercorp/pinpoint/grpc/StatusErrors.java @@ -22,6 +22,7 @@ /** * @author jaehong.kim */ +@Deprecated public class StatusErrors { static final String CONNECTION_REFUSED_MESSAGE = "Connection refused: no further information"; static final String CANCELLED_BEFORE_RECEIVING_HALF_CLOSE = "CANCELLED: cancelled before receiving half close"; diff --git a/grpc/src/test/java/com/navercorp/pinpoint/grpc/ChannelFactoryTest.java b/grpc/src/test/java/com/navercorp/pinpoint/grpc/ChannelFactoryTest.java index 0e0f22159dc6..b8a20980dd30 100644 --- a/grpc/src/test/java/com/navercorp/pinpoint/grpc/ChannelFactoryTest.java +++ b/grpc/src/test/java/com/navercorp/pinpoint/grpc/ChannelFactoryTest.java @@ -210,7 +210,8 @@ public void onNext(PSpanMessage value) { @Override public void onError(Throwable t) { - logger.debug("server-onError:{} status:{}", t.getMessage(), Status.fromThrowable(t), t); + Status status = Status.fromThrowable(t); + logger.debug("server-onError:{}", status); } @Override diff --git a/grpc/src/test/java/com/navercorp/pinpoint/grpc/MessageFormatUtilsTest.java b/grpc/src/test/java/com/navercorp/pinpoint/grpc/MessageFormatUtilsTest.java new file mode 100644 index 000000000000..6a6d739d3084 --- /dev/null +++ b/grpc/src/test/java/com/navercorp/pinpoint/grpc/MessageFormatUtilsTest.java @@ -0,0 +1,46 @@ +package com.navercorp.pinpoint.grpc; + +import com.navercorp.pinpoint.grpc.trace.PSpan; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.Test; + +class MessageFormatUtilsTest { + private final Logger logger = LogManager.getLogger(this.getClass()); + + @Test + void debugLog() { + PSpan.Builder builder = PSpan.newBuilder(); + builder.setApiId(1); + builder.setStartTime(2); + PSpan span = builder.build(); + + MessageFormatUtils.LogMessage logMessage = MessageFormatUtils.debugLog(span); + logger.debug("logMessage:{}", logMessage); + } + + @Test + void debugLog_null() { + + MessageFormatUtils.LogMessage logMessage = MessageFormatUtils.debugLog(null); + logger.debug("logMessage:{}", logMessage); + } + + @Test + void simpleClasName() { + PSpan.Builder builder = PSpan.newBuilder(); + builder.setApiId(1); + builder.setStartTime(2); + PSpan span = builder.build(); + + String name = MessageFormatUtils.getSimpleClasName(span); + logger.debug("message:{}", name); + } + + @Test + void simpleClasName_null() { + String name = MessageFormatUtils.getSimpleClasName(null); + Assertions.assertEquals("null", name); + } +} \ No newline at end of file diff --git a/grpc/src/test/resources/log4j2-test.xml b/grpc/src/test/resources/log4j2-test.xml new file mode 100644 index 000000000000..b31290b79e85 --- /dev/null +++ b/grpc/src/test/resources/log4j2-test.xml @@ -0,0 +1,23 @@ + + + + %d{MM-dd HH:mm:ss.sss} [%15.15t] %clr{%-5level} %clr{%-40.40logger{1.}}{cyan}:%3L -- %msg{nolookups}%n + %d{MM-dd HH:mm:ss.sss} [%15.15t] %-5level %-40.40logger{1.}:%3L -- %msg{nolookups}%n + + + + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/log/log-collector/src/main/java/com/navercorp/pinpoint/log/collector/grpc/LogConnectionHandler.java b/log/log-collector/src/main/java/com/navercorp/pinpoint/log/collector/grpc/LogConnectionHandler.java index 21596511c4ea..49f44ec792ed 100644 --- a/log/log-collector/src/main/java/com/navercorp/pinpoint/log/collector/grpc/LogConnectionHandler.java +++ b/log/log-collector/src/main/java/com/navercorp/pinpoint/log/collector/grpc/LogConnectionHandler.java @@ -22,6 +22,7 @@ import com.navercorp.pinpoint.log.vo.FileKey; import com.navercorp.pinpoint.log.vo.Log; import com.navercorp.pinpoint.log.vo.LogPile; +import io.grpc.Status; import io.grpc.stub.ServerCallStreamObserver; import io.grpc.stub.StreamObserver; import org.apache.logging.log4j.LogManager; @@ -71,7 +72,8 @@ public void onNext(PLogPile pLogPile) { @Override public void onError(Throwable throwable) { - logger.error("Error on log {}: {}", this.fileKey, throwable.getMessage()); + Status status = Status.fromThrowable(throwable); + logger.error("Error on log {}: {}", this.fileKey, status); this.disposable.dispose(); } diff --git a/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/EmptyCommandService.java b/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/EmptyCommandService.java index 9be8ac99b0e5..3bd031cfe5dd 100644 --- a/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/EmptyCommandService.java +++ b/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/EmptyCommandService.java @@ -18,6 +18,8 @@ import com.navercorp.pinpoint.grpc.trace.PCmdMessage; import com.navercorp.pinpoint.grpc.trace.PCmdRequest; import com.navercorp.pinpoint.grpc.trace.ProfilerCommandServiceGrpc; +import io.grpc.Metadata; +import io.grpc.Status; import io.grpc.stub.StreamObserver; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; @@ -33,17 +35,19 @@ public StreamObserver handleCommand(StreamObserver res return new StreamObserver<>() { @Override public void onNext(PCmdMessage pCmdMessage) { - logger.debug("onNext:{}", pCmdMessage); + logger.debug("handleCommand onNext:{}", pCmdMessage); } @Override public void onError(Throwable throwable) { - logger.debug("onError", throwable); + Status status = Status.fromThrowable(throwable); + Metadata metadata = Status.trailersFromThrowable(throwable); + logger.debug("handleCommand onError {} {}", status, metadata); } @Override public void onCompleted() { - logger.debug("onCompleted"); + logger.debug("handleCommand onCompleted"); } }; } @@ -53,17 +57,19 @@ public StreamObserver handleCommandV2(StreamObserver r return new StreamObserver<>() { @Override public void onNext(PCmdMessage pCmdMessage) { - logger.debug("onNext:{}", pCmdMessage); + logger.debug("handleCommandV2 onNext:{}", pCmdMessage); } @Override public void onError(Throwable throwable) { - logger.debug("onError", throwable); + Status status = Status.fromThrowable(throwable); + Metadata metadata = Status.trailersFromThrowable(throwable); + logger.debug("handleCommandV2 onError {} {}", status, metadata); } @Override public void onCompleted() { - logger.debug("onCompleted"); + logger.debug("handleCommandV2 onCompleted"); } }; } diff --git a/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/FluxCommandResponseObserver.java b/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/FluxCommandResponseObserver.java index c805867fe41e..b92bcc6559d3 100644 --- a/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/FluxCommandResponseObserver.java +++ b/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/FluxCommandResponseObserver.java @@ -86,10 +86,11 @@ private FluxSink initSink(T response) { @Override public void onError(Throwable t) { - if (t.getMessage().startsWith("CANCELLED")) { - logger.info("Stream cancelled: sinkId = {}", sinkId); + final Status status = Status.fromThrowable(t); + if (Status.CANCELLED == status) { + logger.info("Stream cancelled: sinkId = {} {}", sinkId, status); } else { - logger.warn("Stream error: sinkId = {}, message = {}", sinkId, t.getMessage(), t); + logger.warn("Stream error: sinkId = {}, {}", sinkId, status); } this.connectionObserver.onCompleted(); diff --git a/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/GrpcCommandService.java b/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/GrpcCommandService.java index ac8b5a9bc9be..9b403d3d51f7 100644 --- a/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/GrpcCommandService.java +++ b/realtime/realtime-collector/src/main/java/com/navercorp/pinpoint/realtime/collector/receiver/grpc/GrpcCommandService.java @@ -19,8 +19,6 @@ import com.google.protobuf.Empty; import com.navercorp.pinpoint.common.server.cluster.ClusterKey; import com.navercorp.pinpoint.grpc.Header; -import com.navercorp.pinpoint.grpc.StatusError; -import com.navercorp.pinpoint.grpc.StatusErrors; import com.navercorp.pinpoint.grpc.server.ServerContext; import com.navercorp.pinpoint.grpc.server.TransportMetadata; import com.navercorp.pinpoint.grpc.trace.PCmdActiveThreadCountRes; @@ -33,6 +31,7 @@ import com.navercorp.pinpoint.grpc.trace.ProfilerCommandServiceGrpc; import com.navercorp.pinpoint.realtime.collector.sink.ErrorSinkRepository; import com.navercorp.pinpoint.realtime.collector.sink.SinkRepository; +import io.grpc.Metadata; import io.grpc.Status; import io.grpc.StatusException; import io.grpc.stub.ServerCallStreamObserver; @@ -239,18 +238,12 @@ private void handleOnError(Throwable t, GrpcAgentConnection conn) { return; } - final StatusError statusError = StatusErrors.throwable(t); - if (statusError.isSimpleError()) { - logger.info("Failed to command stream, {} => local, cause={}", - conn.getClusterKey(), statusError.getMessage()); - } else { - logger.warn( - "Failed to command stream, {} => local, cause={}", - conn.getClusterKey(), - statusError.getMessage(), - statusError.getThrowable() - ); - } + final Status status = Status.fromThrowable(t); + Metadata metadata = Status.trailersFromThrowable(t); + + logger.info("Failed to command stream, {} => local, {} {}", + conn.getClusterKey(), status, metadata); + } private void handleOnCompleted(GrpcAgentConnection conn) { @@ -353,7 +346,8 @@ public void onNext(V t) { @Override public void onError(Throwable t) { - logger.debug("onError", t); + Status status = Status.fromThrowable(t); + logger.debug("onError:{}", status); } @Override