如何“跟踪”日志中的单个事务（Java EE）答案

【问题标题】：How to "follow" individual transaction in logs (Java EE)如何“跟踪”日志中的单个事务（Java EE）
【发布时间】：2012-03-28 20:44:28
【问题描述】：

我们有一个企业应用程序（部署为一个 ear）是一个批处理器，它创建多个线程来同时处理批处理项（达到最大并发线程数）。作为处理的一部分，它调用部署在同一个 Glassfish 中但跨两个域的几个 RESTful Web 服务。每个应用程序都将日志记录到服务器上自己的应用程序日志文件中，并且所有日志也被 Splunk 服务器摄取。

我们被要求找到一种方法来“标记”每个日志语句，以便我们可以搜索所有日志并获取处理一个批处理项目的所有语句。

正在处理的每个项目都有一个唯一的 ID，因此将其添加到处理器日志语句很容易。问题是我们如何标记来自 Web 服务的日志？

一个建议是向每个使用此 ID 的 Web 服务调用添加一个参数，并将其传播到这些服务的每个方法中。我认为对代码进行这种类型的更改以仅传递一个用于日志记录的值是一个疯狂的想法。

有人做过这样的事吗？关于如何识别“属于一起”的日志语句有什么建议吗？

顺便说一句，我们正在使用 slf4j 和 log4j，但正在考虑使用 logback。

更新

我一直致力于将事务 ID 作为 HTTP 标头传递，但似乎无法完全实现。我正在使用泽西岛，这就是我所拥有的：

我的处理器类将其值作为 transactionId 放入日志记录 MDC，并使用 REST 服务客户端进行某些处理：

public Processor
{
    RESTClient myRESTClient = new RESTClient("http://path/to/restService");

    public void process(final Object object)
    {
        //Put the object ID in the logging MDC
        log.debug("Putting '{}' in the MDC as the {} header value.",  object.getObjectID(), "transactionID");
        MDC.put("transactionID", object.getObjectID());

    //Do some stuff

    Object anotherObject = myRESTClient.doQuery(object.getValue());

    //Do more some stuff
    }
}

我的 RESTClient 来访问 REST 服务。在这里，我将 transactionId 从 MDC 中拉出并将其作为标头添加到请求中：

public RESTClient
{
    public Object doQuery(String value)
    {
        Object object = null;

        try
        {
            Builder builder = myRestService.queryParam(PARAM_KEY_VALUE, value)
                    .accept(MediaType.APPLICATION_XML);

            String transactionId = (String) MDC.get("transactionID");

            logger.debug("Retrieved '{}' from MDC for key {}",
                transactionId,
                "transactionID");

            if (this.getTransactionID() != null)
            {
                builder = builder.header("transactionID", transactionId);
            }

            object = builder.get(Object.class);
        }
        catch (Throwable ex)
        {
            //Do error handling
        }
    }
}

我的 REST 服务资源类应该在其请求标头中包含 transactionId 并将其放置在其日志记录 MDC 中：

@Path("/myPath")
public class MyResource
{
    @Context
    private HttpContext httpContext;

    @GET
    @Produces(MediaType.APPLICATION_XML)
    public Object doQuery( @QueryParam("value") String value)
    {
        putTransactionIdInMDC();

        SubscriberAccount account = null;

        try
        {
            //Do query stuff
        }
        catch (Exception ex)
        {
            throw new WebApplicationException(Response.Status.INTERNAL_SERVER_ERROR);
        }

        return account;
    }

    private void putTransactionIdInMDC()
    {
        if (httpContext != null)
        {
            String transactionID = httpContext.getRequest()
                    .getHeaderValue("transactionID");

            if (transactionID != null && transactionID.isEmpty())
            {
                /*
                 * It's not likely, but possible that two headers with the same
                 * header key were put in the request. If so, the value will be
                 * a comma separated list. We're using the first one.
                 */
                String[] strings = transactionID.split(",");

                logger.debug("Header '{}' value(s): {}",
                        "transactionID",
                        strings);

                MDC.put("transactionID", strings[0]);
            }
            else
            {
                logger.debug("The header '{}' was not included in the request.",
                        "transactionID");
            }
        }
        else
        {
            logger.info("Could not get an HttpContext for the request");
        }
    }
}

根据我的日志记录，我知道 transactionId 被放入处理器 MDC 并由 RESTClient 类从中提取。但是，它不会作为 http 标头传递给 REST 服务。谁能告诉我为什么不呢？

处理器日志文件：

2012-04-13T17:30:36.541 MDT  INFO [Ejb-Async-Thread-2] DEBUG my.package.Processor - Putting '12311497-2279-4516-af7d-cf9716f7748a' in the MDC as the transactionId header value.

2012-04-13T17:30:36.541 MDT  INFO [Ejb-Async-Thread-2] DEBUG my.package.RESTClient- Retrieved '12311497-2279-4516-af7d-cf9716f7748a' from MDC for key transactionId

REST 服务日志文件：

2012 Apr 13 17:30:36,337 MDT [http-thread-pool-80(3)] DEBUG my.package.MyResource - The header 'transactionId' was not included in the request.

更新两次

在我上面的代码中发现了逻辑错误：

if (transactionID != null && transactionID.isEmpty())

应该是：

if (transactionID != null !&& transactionID.isEmpty())

【问题讨论】：

标签： jakarta-ee logging jersey grouping

【解决方案1】：

只是一个模糊的想法：也许您可以使用 SOAP 信封从业务数据中“隐藏”那个讨厌的工作 ID。并且在客户端使用某种拦截器或 JAX-WS 处理程序可以将其设置到请求中，而无需触及业务代码。在服务器端，另一个处理程序或拦截器可以从信封中提取 id 并使用 NDC（嵌套诊断上下文）或 MDC（映射诊断上下文）将其填充到 Log4J 内容中。然后必须调整日志格式以实际记录 NDC/MDC 值。

【讨论】：

感谢您的建议。不幸的是，我们的服务是 RESTful 服务。我已经更新了 OP 以进行澄清。
@sdoca：我确信 JAX-RS 规范或您友好的 JEE 服务器供应商都为 JAX-RS 请求提供了拦截器。 HTTP-header 可以包含附加标签。原理是一样的，只是措辞有点不同。
您添加标题的想法很棒。谢谢！

【解决方案2】：

如果您要 Splunk 来自所有参与批处理的服务器的所有日志文件，并且您有 唯一 id 可以使用，那么在 Splunk 中它非常简单将构成每个单独批处理流的事件关联在一起。

您需要查看 Splunk Transaction 搜索命令

至于将唯一 ID 添加到 Web 服务日志，如前所述，HTTP 标头可能是侵入性最小的方式。而且我不认为这很疯狂，想想你会的操作可见性级别现在触手可及:)

这里有更多关于Splunk Best Practice Logging的信息。

【讨论】：