From 7be66a3132cab8dca3fdd84e886abbe82cb736bc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Do=C4=9Fa=C3=A7=20Eldenk?= Date: Tue, 13 Aug 2024 01:23:55 -0500 Subject: [PATCH] fix: logging service RPC json serialization --- .../logging/JsonLogFormatterBuilder.java | 19 ++- .../common/logging/JsonLogFormatterTest.java | 15 ++ .../it/grpc/GrpcLoggingServiceTest.java | 131 ++++++++++++++++++ 3 files changed, 162 insertions(+), 3 deletions(-) create mode 100644 grpc/src/test/java/com/linecorp/armeria/it/grpc/GrpcLoggingServiceTest.java diff --git a/core/src/main/java/com/linecorp/armeria/common/logging/JsonLogFormatterBuilder.java b/core/src/main/java/com/linecorp/armeria/common/logging/JsonLogFormatterBuilder.java index 4f89e2939a4..93797811ec4 100644 --- a/core/src/main/java/com/linecorp/armeria/common/logging/JsonLogFormatterBuilder.java +++ b/core/src/main/java/com/linecorp/armeria/common/logging/JsonLogFormatterBuilder.java @@ -23,8 +23,10 @@ import com.fasterxml.jackson.databind.JsonNode; import com.fasterxml.jackson.databind.ObjectMapper; +import com.fasterxml.jackson.databind.node.ObjectNode; import com.linecorp.armeria.common.RequestContext; +import com.linecorp.armeria.common.RpcRequest; import com.linecorp.armeria.common.annotation.Nullable; import com.linecorp.armeria.common.annotation.UnstableApi; import com.linecorp.armeria.internal.common.JacksonUtil; @@ -58,7 +60,7 @@ public LogFormatter build() { final HeadersSanitizer defaultHeadersSanitizer = defaultHeadersSanitizer(objectMapper); final BiFunction defaultContentSanitizer = - defaultSanitizer(objectMapper); + defaultContentSanitizer(objectMapper); return new JsonLogFormatter( firstNonNull(requestHeadersSanitizer(), HeadersSanitizer.ofJson()), firstNonNull(responseHeadersSanitizer(), HeadersSanitizer.ofJson()), @@ -70,8 +72,19 @@ public LogFormatter build() { } private static BiFunction - defaultSanitizer(ObjectMapper objectMapper) { - return (requestContext, obj) -> objectMapper.valueToTree(obj); + defaultContentSanitizer(ObjectMapper objectMapper) { + return (requestContext, obj) -> { + if (obj instanceof RpcRequest) { + RpcRequest rpcRequest = (RpcRequest) obj; + ObjectNode node = objectMapper.createObjectNode(); + node.put("method", rpcRequest.method()); + node.put("serviceName", rpcRequest.serviceName()); +// node.set("params", objectMapper.valueToTree(rpcRequest.params())); + + return node; + } + return objectMapper.valueToTree(obj); + }; } private static HeadersSanitizer diff --git a/core/src/test/java/com/linecorp/armeria/common/logging/JsonLogFormatterTest.java b/core/src/test/java/com/linecorp/armeria/common/logging/JsonLogFormatterTest.java index 41a31695f22..4b9b9d16a76 100644 --- a/core/src/test/java/com/linecorp/armeria/common/logging/JsonLogFormatterTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/logging/JsonLogFormatterTest.java @@ -42,6 +42,7 @@ import com.linecorp.armeria.common.RequestHeaders; import com.linecorp.armeria.common.RequestId; import com.linecorp.armeria.common.ResponseHeaders; +import com.linecorp.armeria.common.RpcRequest; import com.linecorp.armeria.common.annotation.Nullable; import com.linecorp.armeria.server.ServiceRequestContext; @@ -60,6 +61,20 @@ void formatRequest() { "\"duration\":\".+\",\"scheme\":\".+\",\"name\":\".+\",\"headers\":\\{\".+\"}}$"); } + @Test + void formatRpcRequest() { + final LogFormatter logFormatter = LogFormatter.ofJson(); + final ServiceRequestContext ctx = ServiceRequestContext.of(HttpRequest.of(HttpMethod.POST, "/com.Foo")); + final DefaultRequestLog log = (DefaultRequestLog) ctx.log(); + log.requestContent(RpcRequest.of(DefaultRequestLogTest.class, "service", "method"), null); + log.endRequest(); + final String requestLog = logFormatter.formatRequest(log); + System.out.println(requestLog); + assertThat(requestLog) + .matches("^\\{\"type\":\"request\",\"startTime\":\".+\",\"length\":\".+\"," + + "\"duration\":\".+\",\"scheme\":\".+\",\"name\":\".+\",\"headers\":\\{\".+\"}}$"); + } + @Test void formatResponse() { final LogFormatter logFormatter = LogFormatter.ofJson(); diff --git a/grpc/src/test/java/com/linecorp/armeria/it/grpc/GrpcLoggingServiceTest.java b/grpc/src/test/java/com/linecorp/armeria/it/grpc/GrpcLoggingServiceTest.java new file mode 100644 index 00000000000..b5080a11765 --- /dev/null +++ b/grpc/src/test/java/com/linecorp/armeria/it/grpc/GrpcLoggingServiceTest.java @@ -0,0 +1,131 @@ +/* + * Copyright 2022 LINE Corporation + * + * LINE Corporation licenses this file to you under the Apache License, + * version 2.0 (the "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at: + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT + * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the + * License for the specific language governing permissions and limitations + * under the License. + */ + +package com.linecorp.armeria.it.grpc; + +import static net.javacrumbs.jsonunit.fluent.JsonFluentAssert.assertThatJson; +import static org.mockito.ArgumentMatchers.anyString; +import static org.mockito.Mockito.doNothing; +import static org.mockito.Mockito.doReturn; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; + +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; +import org.mockito.ArgumentCaptor; +import org.slf4j.Logger; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.google.protobuf.ByteString; + +import com.linecorp.armeria.client.grpc.GrpcClients; +import com.linecorp.armeria.common.logging.LogFormatter; +import com.linecorp.armeria.common.logging.LogLevel; +import com.linecorp.armeria.common.logging.LogWriter; +import com.linecorp.armeria.server.ServerBuilder; +import com.linecorp.armeria.server.grpc.GrpcService; +import com.linecorp.armeria.server.logging.LoggingService; +import com.linecorp.armeria.testing.junit5.server.ServerExtension; + +import io.grpc.stub.StreamObserver; +import testing.grpc.Messages.Payload; +import testing.grpc.Messages.PayloadType; +import testing.grpc.Messages.SimpleRequest; +import testing.grpc.Messages.SimpleRequest.NestedRequest; +import testing.grpc.Messages.SimpleResponse; +import testing.grpc.TestServiceGrpc.TestServiceBlockingStub; +import testing.grpc.TestServiceGrpc.TestServiceImplBase; + +class GrpcLoggingServiceTest { + + @RegisterExtension + static final ServerExtension server = new ServerExtension() { + @Override + protected void configure(ServerBuilder sb) { + sb.requestTimeoutMillis(5000); + sb.service(GrpcService.builder() + .addService(new FirstTestServiceImpl()) + .build()); + } + }; + + @Test + void methodDecorators() throws Exception { + final Logger logger = mock(Logger.class); + doReturn(true).when(logger).isInfoEnabled(); + doNothing().when(logger).info(anyString()); + + server.server().reconfigure(sb -> { + sb.decorator( + LoggingService.builder() + .samplingRate(1) + .logWriter( + LogWriter.builder() + .logger(logger) + .logFormatter(LogFormatter.ofJson()) + .requestLogLevel(LogLevel.INFO) + .successfulResponseLogLevel(LogLevel.INFO) + .build() + ) + .newDecorator() + ); + sb.service(GrpcService.builder() + .addService(new FirstTestServiceImpl()) + .build()); + }); + + final TestServiceBlockingStub client = GrpcClients.newClient(server.httpUri(), + TestServiceBlockingStub.class); + + client.unaryCall(SimpleRequest.newBuilder() + .setPayload( + Payload.newBuilder() + .setBody(ByteString.copyFromUtf8("Hello World!")) + .setType(PayloadType.COMPRESSABLE) + .build() + ) + .setFillUsername(true) + .setNestedRequest( + NestedRequest.newBuilder() + .setNestedPayload("zanzibar") + .build() + ) + .build()); + + // Verify that the logger was called with the expected arguments. + ArgumentCaptor messageCaptor = ArgumentCaptor.forClass(String.class); + verify(logger).isInfoEnabled(); + verify(logger).info(messageCaptor.capture()); + + final ObjectMapper objectMapper = new ObjectMapper(); + JsonNode node = objectMapper.readTree(messageCaptor.getValue()); + + assertThatJson(node).node("request.payload.body").isEqualTo("Hello World!"); + } + + private static class FirstTestServiceImpl extends TestServiceImplBase { + + @Override + public void unaryCall(SimpleRequest request, StreamObserver responseObserver) { + responseObserver.onNext(SimpleResponse.newBuilder() + .setUsername("test user") + .build()); + responseObserver.onCompleted(); + } + } +}