如何使用gRPC拦截器在Spring Boot应用程序中连接/更新日志记录MDC

Question

我有一个Spring-Boot应用程序，我也在其中启动一个gRPC服务器/服务。servlet和gRPC代码都将请求发送到一个公共对象来处理请求。当请求进来时，我想更新日志记录以显示唯一的“ID”，这样我就可以通过系统跟踪请求。

在Spring端，我设置了一个“过滤器”，用于更新日志MDC，以便向日志请求添加一些数据（参见本例）。这个很好用

在gRPC方面，我创建了一个“服务器拦截器”并将其添加到服务中，而拦截器被调用时，更新MDC的代码不会坚持，所以当请求通过gRPC服务时，我不会在日志中打印ID。我意识到这与我在一个线程中拦截调用，而它在另一个线程中被gRPC调度的事实有关，我似乎不知道如何在执行工作的线程中拦截调用，或者添加MDC信息，以便将其正确地传播到执行工作的线程。

我做了很多搜索，很惊讶没有发现这个问题，我只能假设我的查询技巧是缺乏的：（

我是gRPC的新手，这是我写的第一个拦截器。我尝试了几种不同的方式添加拦截器（通过ServerInterceptors.intercept、BindableService instance.intercept）。

我看过LogNet的Spring Boot gRPC Starter，但我不确定这是否能解决这个问题。

下面是我在拦截器类中添加的代码

@Override
public <ReqT, RespT> ServerCall.Listener<ReqT> interceptCall(final ServerCall<ReqT, RespT> call, final Metadata headers, final ServerCallHandler<ReqT, RespT> next) {
    try {
        final String mdcData = String.format("[requestID=%s]",
            UUID.randomUUID().toString());
    MDC.put(MDC_DATA_KEY, mdcData);
    return next.startCall(call, headers);
    } finally {
        MDC.clear();
    }
}

当一个请求通过RESTful API进来时，我看到日志输出是这样的

2019-04-09 10:19:16.331 [requestID=380e28db-c8da-4e35-a097-4b8c90c006f4] INFO 87100 --- [nio-8080-exec-1] c.c.es.xxx: processing request step 1
2019-04-09 10:19:16.800 [requestID=380e28db-c8da-4e35-a097-4b8c90c006f4] INFO 87100 --- [nio-8080-exec-1] c.c.es.xxx: processing request step 2
2019-04-09 10:19:16.803 [requestID=380e28db-c8da-4e35-a097-4b8c90c006f4] INFO 87100 --- [nio-8080-exec-1] c.c.es.xxx: Processing request step 3
...

当请求通过gRPC服务时，我希望得到类似的输出。

谢啦

Answer 1

由于没有人回复，我一直在尝试，并为我的interceptCall函数想出了以下解决方案。我不是100%确定这为什么有效，但它适用于我的用例。

    private class LogInterceptor implements ServerInterceptor {
        @Override
        public <ReqT, RespT> ServerCall.Listener<ReqT> interceptCall(final ServerCall<ReqT, RespT> call,
                                                                     final Metadata headers,
                                                                     final ServerCallHandler<ReqT, RespT> next) {
            Context context = Context.current();
            final String requestId = UUID.randomUUID().toString();
            return Contexts.interceptCall(context, call, headers, new ServerCallHandler<ReqT, RespT>() {
                @Override
                public ServerCall.Listener<ReqT> startCall(ServerCall<ReqT, RespT> call, Metadata headers) {

                    return new ForwardingServerCallListener.SimpleForwardingServerCallListener<ReqT>(next.startCall(call, headers)) {
                        /**
                         * The actual service call happens during onHalfClose().
                         */
                        @Override
                        public void onHalfClose() {
                            try (final CloseableThreadContext.Instance ctc = CloseableThreadContext.put("requestID",
                                    UUID.randomUUID().toString())) {
                                super.onHalfClose();
                            }
                        }
                    };
                }
            });
        }
    }

在我的申请中。我添加了以下内容（我已经有了）

登录中。图案级别=[%X]-5级别

“%X”告诉日志系统打印所有CloseableThreadContext键/值。

希望这能帮助其他人。