diff --git a/examples/README.md b/examples/README.md index 91fde2c045c..f67f1f90ec3 100644 --- a/examples/README.md +++ b/examples/README.md @@ -125,6 +125,8 @@ $ bazel-bin/hello-world-client - [OAuth2-based Authentication](example-oauth) +- [Log4j 2 logging context](example-log4j2) + - [Pre-serialized messages](src/main/java/io/grpc/examples/preserialized) ## Unit test examples diff --git a/examples/example-log4j2/README.md b/examples/example-log4j2/README.md new file mode 100644 index 00000000000..d8f97492f78 --- /dev/null +++ b/examples/example-log4j2/README.md @@ -0,0 +1,67 @@ +gRPC Log4j 2 Example +============================================== + +This example illustrates how to set the Log4j 2 `ThreadContext` from a server interceptor so that +it is picked up by the logger in your server. + +The server interceptor puts a `requestId` (a randomly generated UUID) and the `clientName` taken +from a request header into the `ThreadContext`. The `%X` conversion pattern in +[log4j2.xml](src/main/resources/log4j2.xml) then appends both values to every log statement made +while the call is being handled, so the service method itself does not have to pass them around. + +These values are deliberately *not* stored in an `io.grpc.Context`: logging frameworks read from +thread-local storage, so the interceptor sets and clears the `ThreadContext` around each callback +using `CloseableThreadContext`. + +### Build the example + +The examples require `grpc-java` to already be built. You are strongly encouraged to check out a +git release tag, since there will already be a build of gRPC available. Otherwise you must follow +[COMPILING](../../COMPILING.md). + +From the `grpc-java/examples/example-log4j2` directory: +``` +$ ../gradlew installDist +``` + +This creates the scripts `build/install/example-log4j2/bin/custom-log-server` and +`build/install/example-log4j2/bin/custom-log-client`. + +### Run the example + +1. To start the server on its default port of 50051, run: +``` +$ ./build/install/example-log4j2/bin/custom-log-server +``` + +2. In a different terminal window, run the client: +``` +$ ./build/install/example-log4j2/bin/custom-log-client +``` + +The server logs a line for each request that includes the contextual values appended by `%X`: + +``` +2026/09/14 15:22:12:686 PDT INFO CustomLogServer - Got a request {requestId=3e6c256d-6e87-411e-8bf3-fbf81e7ce0e6, clientName=my.domain.name} +``` + +Log statements made outside of an RPC, such as the server's startup message, are unaffected: + +``` +2026/09/14 15:22:04:132 PDT INFO CustomLogServer - Server started, listening on 50051 +``` + +### Why each callback sets the context + +gRPC does not guarantee that every callback for a call runs on the same thread, and an application +that supplies its own call executor may have each callback handled by a different worker. Logging +frameworks read from thread-local storage, so the values have to be established on whichever thread +is actually running the code that logs. That is why each `ServerCall.Listener` callback re-populates +the `ThreadContext` and clears it again on the way out, instead of the interceptor setting it once +and leaving it. + +The context is also established around `next.startCall()`, so that interceptors further down the +chain see these values while their own `interceptCall()` runs. + +For more information, refer to gRPC Java's [README](../../README.md) and +[tutorial](https://grpc.io/docs/languages/java/basics). diff --git a/examples/example-log4j2/build.gradle b/examples/example-log4j2/build.gradle new file mode 100644 index 00000000000..314f5b1bc0a --- /dev/null +++ b/examples/example-log4j2/build.gradle @@ -0,0 +1,71 @@ +plugins { + id 'application' // Provide convenience executables for trying out the examples. + id 'com.google.protobuf' version '0.9.5' + // Generate IntelliJ IDEA's .idea & .iml project files + id 'idea' + id 'java' +} + +repositories { + mavenCentral() + mavenLocal() +} + +java { + sourceCompatibility = JavaVersion.VERSION_1_8 + targetCompatibility = JavaVersion.VERSION_1_8 +} + +// IMPORTANT: You probably want the non-SNAPSHOT version of gRPC. Make sure you +// are looking at a tagged version of the example and not "master"! + +// Feel free to delete the comment at the next line. It is just for safely +// updating the version in our release process. +def grpcVersion = '1.85.0-SNAPSHOT' // CURRENT_GRPC_VERSION +def protocVersion = '3.25.8' +def log4jVersion = '2.26.1' + +dependencies { + implementation "io.grpc:grpc-protobuf:${grpcVersion}" + implementation "io.grpc:grpc-stub:${grpcVersion}" + implementation "org.apache.logging.log4j:log4j-api:${log4jVersion}" + runtimeOnly "io.grpc:grpc-netty-shaded:${grpcVersion}" + // The Log4j 2 implementation is only needed at runtime; the example compiles against the API. + runtimeOnly "org.apache.logging.log4j:log4j-core:${log4jVersion}" +} + +protobuf { + protoc { artifact = "com.google.protobuf:protoc:${protocVersion}" } + plugins { + grpc { artifact = "io.grpc:protoc-gen-grpc-java:${grpcVersion}" } + } + generateProtoTasks { + all()*.plugins { grpc {} } + } +} + +startScripts.enabled = false + +task customLogServer(type: CreateStartScripts) { + mainClass = 'io.grpc.examples.logcontext.CustomLogServer' + applicationName = 'custom-log-server' + outputDir = new File(project.buildDir, 'tmp/scripts/' + name) + classpath = startScripts.classpath +} + +task customLogClient(type: CreateStartScripts) { + mainClass = 'io.grpc.examples.logcontext.CustomLogClient' + applicationName = 'custom-log-client' + outputDir = new File(project.buildDir, 'tmp/scripts/' + name) + classpath = startScripts.classpath +} + +application { + applicationDistribution.into('bin') { + from(customLogServer) + from(customLogClient) + filePermissions { + unix(0755) + } + } +} diff --git a/examples/example-log4j2/settings.gradle b/examples/example-log4j2/settings.gradle new file mode 100644 index 00000000000..d553cc5f674 --- /dev/null +++ b/examples/example-log4j2/settings.gradle @@ -0,0 +1,17 @@ +pluginManagement { + // https://issuetracker.google.com/issues/342522142#comment8 + // use D8/R8 8.0.44 or 8.1.44 with AGP 7.4 if needed. + buildscript { + repositories { + mavenCentral() + maven { + url = uri("https://storage.googleapis.com/r8-releases/raw") + } + } + dependencies { + classpath("com.android.tools:r8:8.1.44") + } + } +} + +rootProject.name = 'example-log4j2' diff --git a/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/CustomLogClient.java b/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/CustomLogClient.java new file mode 100644 index 00000000000..2985f7bcea4 --- /dev/null +++ b/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/CustomLogClient.java @@ -0,0 +1,129 @@ +/* + * Copyright 2026 The gRPC Authors + * + * Licensed 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 + * + * http://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 io.grpc.examples.logcontext; + +import io.grpc.CallOptions; +import io.grpc.Channel; +import io.grpc.ClientCall; +import io.grpc.ClientInterceptor; +import io.grpc.ForwardingClientCall.SimpleForwardingClientCall; +import io.grpc.Grpc; +import io.grpc.InsecureChannelCredentials; +import io.grpc.ManagedChannel; +import io.grpc.Metadata; +import io.grpc.MethodDescriptor; +import io.grpc.StatusRuntimeException; +import io.grpc.examples.helloworld.GreeterGrpc; +import io.grpc.examples.helloworld.HelloReply; +import io.grpc.examples.helloworld.HelloRequest; +import java.net.InetAddress; +import java.net.UnknownHostException; +import java.util.concurrent.TimeUnit; +import java.util.logging.Level; +import java.util.logging.Logger; + +/** + * A client like {@link io.grpc.examples.helloworld.HelloWorldClient} that sends the header + * {@link CustomLogServer} logs. + * + *

The client itself does not use Log4j 2; it only supplies the {@code clientName} header that + * {@link HeaderServerInterceptor} copies into the server's logging context. + */ +public class CustomLogClient { + + private static final Logger logger = Logger.getLogger(CustomLogClient.class.getName()); + + // Resolved once rather than per RPC: InetAddress.getLocalHost() may block on a DNS lookup, and + // start() runs on the calling thread. + private static final String LOCAL_HOST_NAME = localHostName(); + + private final GreeterGrpc.GreeterBlockingStub blockingStub; + + /** Construct a client for accessing the server using the existing channel. */ + public CustomLogClient(Channel channel) { + // 'channel' here is a Channel, not a ManagedChannel, so it is not this code's responsibility to + // shut it down. + blockingStub = GreeterGrpc.newBlockingStub(channel).withInterceptors(new ClientInterceptor() { + @Override + public ClientCall interceptCall( + MethodDescriptor method, CallOptions callOptions, Channel next) { + return new SimpleForwardingClientCall(next.newCall(method, callOptions)) { + @Override + public void start(Listener responseListener, Metadata headers) { + headers.put(HeaderServerInterceptor.CLIENT_NAME_KEY, LOCAL_HOST_NAME); + super.start(responseListener, headers); + } + }; + } + }); + } + + private static String localHostName() { + try { + return InetAddress.getLocalHost().getHostName(); + } catch (UnknownHostException e) { + logger.log(Level.WARNING, "Unable to determine the local host name", e); + return "unknown"; + } + } + + /** Say hello to the server. */ + public void greet(String name) { + logger.info("Will try to greet " + name + " ..."); + HelloRequest request = HelloRequest.newBuilder().setName(name).build(); + HelloReply response; + try { + response = blockingStub.sayHello(request); + } catch (StatusRuntimeException e) { + logger.log(Level.WARNING, "RPC failed: {0}", e.getStatus()); + return; + } + logger.info("Greeting: " + response.getMessage()); + } + + /** + * Greet the server. If provided, the first element of {@code args} is the name to use in the + * greeting. The second argument is the target server. + */ + public static void main(String[] args) throws Exception { + String user = "world"; + // Access a service running on the local machine on port 50051 + String target = "localhost:50051"; + if (args.length > 0) { + if ("--help".equals(args[0])) { + System.err.println("Usage: [name [target]]"); + System.err.println(""); + System.err.println(" name The name you wish to be greeted by. Defaults to " + user); + System.err.println(" target The server to connect to. Defaults to " + target); + System.exit(1); + } + user = args[0]; + } + if (args.length > 1) { + target = args[1]; + } + + ManagedChannel channel = Grpc.newChannelBuilder(target, InsecureChannelCredentials.create()) + .build(); + try { + CustomLogClient client = new CustomLogClient(channel); + client.greet(user); + } finally { + channel.shutdownNow().awaitTermination(5, TimeUnit.SECONDS); + } + } +} diff --git a/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/CustomLogServer.java b/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/CustomLogServer.java new file mode 100644 index 00000000000..69130e5089e --- /dev/null +++ b/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/CustomLogServer.java @@ -0,0 +1,108 @@ +/* + * Copyright 2026 The gRPC Authors + * + * Licensed 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 + * + * http://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 io.grpc.examples.logcontext; + +import io.grpc.Grpc; +import io.grpc.InsecureServerCredentials; +import io.grpc.Server; +import io.grpc.ServerInterceptors; +import io.grpc.examples.helloworld.GreeterGrpc; +import io.grpc.examples.helloworld.HelloReply; +import io.grpc.examples.helloworld.HelloRequest; +import io.grpc.stub.StreamObserver; +import java.io.IOException; +import java.util.concurrent.TimeUnit; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; + +/** + * A server like {@link io.grpc.examples.helloworld.HelloWorldServer} that logs through Log4j 2. + * + *

It installs {@link HeaderServerInterceptor}, which puts a request id and the client name into + * the Log4j 2 {@code ThreadContext}. The {@code %X} conversion pattern in {@code log4j2.xml} then + * appends those values to every log statement the service makes, without the service having to pass + * them around itself. + */ +public class CustomLogServer { + + private static final Logger logger = LogManager.getLogger(CustomLogServer.class); + + /* The port on which the server should run */ + private static final int PORT = 50051; + + private Server server; + + private void start() throws IOException { + server = Grpc.newServerBuilderForPort(PORT, InsecureServerCredentials.create()) + .addService(ServerInterceptors.intercept(new GreeterImpl(), new HeaderServerInterceptor())) + .build() + .start(); + logger.info("Server started, listening on {}", PORT); + Runtime.getRuntime().addShutdownHook(new Thread() { + @Override + public void run() { + // Use stderr here since the logger may have been reset by its JVM shutdown hook. + System.err.println("*** shutting down gRPC server since JVM is shutting down"); + try { + CustomLogServer.this.stop(); + } catch (InterruptedException e) { + e.printStackTrace(System.err); + } + System.err.println("*** server shut down"); + } + }); + } + + private void stop() throws InterruptedException { + if (server != null) { + server.shutdown().awaitTermination(30, TimeUnit.SECONDS); + } + } + + /** + * Await termination on the main thread since the grpc library uses daemon threads. + */ + private void blockUntilShutdown() throws InterruptedException { + if (server != null) { + server.awaitTermination(); + } + } + + /** + * Main launches the server from the command line. + */ + public static void main(String[] args) throws IOException, InterruptedException { + final CustomLogServer server = new CustomLogServer(); + server.start(); + server.blockUntilShutdown(); + } + + private static class GreeterImpl extends GreeterGrpc.GreeterImplBase { + + @Override + public void sayHello(HelloRequest req, StreamObserver responseObserver) { + // The ThreadContext set by HeaderServerInterceptor is still in place here, so this outputs + // something like: + // 2026/09/14 15:22:12:686 PDT INFO CustomLogServer - Got a request + // {requestId=3e6c256d-6e87-411e-8bf3-fbf81e7ce0e6, clientName=my.domain.name} + logger.info("Got a request"); + HelloReply reply = HelloReply.newBuilder().setMessage("Hello " + req.getName()).build(); + responseObserver.onNext(reply); + responseObserver.onCompleted(); + } + } +} diff --git a/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/HeaderServerInterceptor.java b/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/HeaderServerInterceptor.java new file mode 100644 index 00000000000..20464ec5d46 --- /dev/null +++ b/examples/example-log4j2/src/main/java/io/grpc/examples/logcontext/HeaderServerInterceptor.java @@ -0,0 +1,112 @@ +/* + * Copyright 2026 The gRPC Authors + * + * Licensed 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 + * + * http://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 io.grpc.examples.logcontext; + +import io.grpc.ForwardingServerCallListener.SimpleForwardingServerCallListener; +import io.grpc.Metadata; +import io.grpc.ServerCall; +import io.grpc.ServerCallHandler; +import io.grpc.ServerInterceptor; +import java.util.UUID; +import org.apache.logging.log4j.CloseableThreadContext; +import org.apache.logging.log4j.CloseableThreadContext.Instance; + +/** + * A server interceptor that puts per-call values into the Log4j 2 {@code ThreadContext} so that + * every log statement made while handling the call is automatically annotated with them. + * + *

The values are scoped to the thread rather than to an {@link io.grpc.Context}, because that is + * what logging frameworks read from. Each callback re-populates the {@code ThreadContext} and + * clears it again on the way out, since gRPC does not guarantee that every callback for a call runs + * on the same thread. + * + *

The context is also established around {@code next.startCall()}, so that interceptors further + * down the chain, and the handler's own call setup, see these values too. + */ +public class HeaderServerInterceptor implements ServerInterceptor { + + private static final String REQUEST_ID_NAME = "requestId"; + + static final Metadata.Key CLIENT_NAME_KEY = + Metadata.Key.of("clientName", Metadata.ASCII_STRING_MARSHALLER); + + /** + * Populates the Log4j 2 {@code ThreadContext} for the duration of the try-with-resources block + * that calls this method, restoring whatever was there before on the way out. + */ + private static Instance logContext(String requestId, String clientName) { + return CloseableThreadContext.put(REQUEST_ID_NAME, requestId) + .put(CLIENT_NAME_KEY.originalName(), clientName); + } + + @Override + public ServerCall.Listener interceptCall( + ServerCall call, + final Metadata requestHeaders, + ServerCallHandler next) { + + final String requestId = UUID.randomUUID().toString(); + final String headerValue = requestHeaders.get(CLIENT_NAME_KEY); + final String clientName = headerValue != null ? headerValue : "unknown"; + + final ServerCall.Listener delegate; + try (Instance ignored = logContext(requestId, clientName)) { + delegate = next.startCall(call, requestHeaders); + } + + return new SimpleForwardingServerCallListener(delegate) { + + @Override + public void onCancel() { + try (Instance ignored = logContext(requestId, clientName)) { + super.onCancel(); + } + } + + @Override + public void onComplete() { + try (Instance ignored = logContext(requestId, clientName)) { + super.onComplete(); + } + } + + @Override + public void onMessage(ReqT message) { + try (Instance ignored = logContext(requestId, clientName)) { + super.onMessage(message); + } + } + + @Override + public void onReady() { + try (Instance ignored = logContext(requestId, clientName)) { + super.onReady(); + } + } + + @Override + public void onHalfClose() { + // For unary calls this is the callback that invokes the service method, so this is the one + // that matters most. The others are here so that the pattern is correct if this code is + // copied into a streaming service. + try (Instance ignored = logContext(requestId, clientName)) { + super.onHalfClose(); + } + } + }; + } +} diff --git a/examples/example-log4j2/src/main/proto/helloworld/helloworld.proto b/examples/example-log4j2/src/main/proto/helloworld/helloworld.proto new file mode 100644 index 00000000000..442539973a0 --- /dev/null +++ b/examples/example-log4j2/src/main/proto/helloworld/helloworld.proto @@ -0,0 +1,37 @@ +// Copyright 2026 The gRPC Authors +// +// Licensed 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 +// +// http://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. +syntax = "proto3"; + +option java_multiple_files = true; +option java_package = "io.grpc.examples.helloworld"; +option java_outer_classname = "HelloWorldProto"; +option objc_class_prefix = "HLW"; + +package helloworld; + +// The greeting service definition. +service Greeter { + // Sends a greeting + rpc SayHello (HelloRequest) returns (HelloReply) {} +} + +// The request message containing the user's name. +message HelloRequest { + string name = 1; +} + +// The response message containing the greetings +message HelloReply { + string message = 1; +} diff --git a/examples/example-log4j2/src/main/resources/log4j2.xml b/examples/example-log4j2/src/main/resources/log4j2.xml new file mode 100644 index 00000000000..4aabcd48d6c --- /dev/null +++ b/examples/example-log4j2/src/main/resources/log4j2.xml @@ -0,0 +1,35 @@ + + + + + + + + + + + + + + +