GKE迁移Logback后Cloud Logging并行请求场景日志丢失问题咨询

问题背景 #

• 此前GKE上部署的基于Log4j2的Spring Boot应用日志上报完全正常：使用Jmeter并行发起100笔事务时，Rest Controller全流程（入口、处理中段、返回前结束节点）的所有日志均可在Cloud Logging中检索到，无异常。
• 近期参照Spring Cloud GCP官方日志集成指南，将日志框架从Log4j2迁移至Logback以实现与Cloud Logging的深度集成，本次迁移仅替换了Log4j到Logback的日志依赖，未改动业务逻辑。迁移后日志可正常上报至Cloud Logging，但出现了偶发日志丢失的异常现象。

异常复现规律 #

压测时用于检索的三类日志关键字如下：

"This is a message "
"This is the mid of controller"
"End of trx, cleaning MDC context : "

业务代码中的日志埋点逻辑覆盖Rest Controller入口、处理逻辑中段、返回响应前结束节点三个位置：

Logger.info("Starting transaction: ", transactionId);
Logger.info("This is the mid of controller");
Logger.info("End of trx, cleaning MDC context : ", transactionId);
MDC.clear();
return response;

异常复现的具体规律：

• 使用Jmeter发起30笔并行事务，首次测试可查询到服务产生的全部日志
• 间隔1分钟重复相同压测时，仅能查询到部分日志，例如仅能检索到30条*Starting transaction:*日志、22条"This is the mid of controller"日志、2条"End of trx, cleaning MDC context : "日志
• 再次重复压测时，日志丢失情况加剧，仅能检索到20条*Starting transaction:*日志，其余两类日志数量为0
• 若等待5分钟后再次压测，又可查询到全部30笔事务的三类完整日志
• 部分场景下甚至会出现某笔事务的所有日志完全无法检索的情况

所有压测场景下服务业务响应均正常：即使存在日志丢失，请求均返回200 success状态码及符合预期的响应体，无业务逻辑不一致问题，服务运行状态正常。

已验证排除的干扰项 #

• 本地环境同场景验证：每秒并行发起100笔事务并长时间循环，将日志写入本地文件时可查询到全部日志，无丢失问题，该异常仅出现在GKE环境中。
• 线程安全验证：已知@RestController是线程安全的，测试过程中未发现日志或响应存在逻辑不一致问题。
• MDC配置验证：Logback配置中已开启includeMDC，业务逻辑中通过MDC.put("transactionId", transactionId)将事务ID写入MDC上下文，MDC本身是线程安全组件，排除该部分配置问题。
• 手动请求验证：使用Postman手动发送请求时可查询到全量日志，无丢失情况。

待确认疑问 #

1. Cloud Logging是否会自动丢弃相似日志？本次所有Jmeter测试的请求内容完全一致，不同事务仅存在Rest Controller入口生成的transactionId差异。
2. Cloud Logging是否会丢弃短时间内并行事务产生的高相似度日志？

现有配置参考 #

Logback配置文件 #

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/cloud/gcp/autoconfigure/logging/logback-appender.xml"/>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>

    <appender name="CONSOLE_JSON_APP" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="org.springframework.cloud.gcp.logging.StackdriverJsonLayout">
                <includeTraceId>true</includeTraceId>
                <includeSpanId>true</includeSpanId>
                <includeLevel>true</includeLevel>
                <includeThreadName>true</includeThreadName>
                <includeMDC>true</includeMDC>
                <includeLoggerName>true</includeLoggerName>
                <includeContextName>true</includeContextName>
                <includeMessage>true</includeMessage>

                <includeFormattedMessage>true</includeFormattedMessage>
                <includeExceptionInMessage>true</includeExceptionInMessage>
                <includeException>true</includeException>

                <serviceContext>
                    <service>APP-LOG</service>
                </serviceContext>
            </layout>
        </encoder>
    </appender>

    <appender name="CONSOLE_JSON_EXT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="org.springframework.cloud.gcp.logging.StackdriverJsonLayout">
                <projectId>${projectId}</projectId>
                <includeTraceId>true</includeTraceId>
                <includeSpanId>true</includeSpanId>
                <includeLevel>true</includeLevel>
                <includeThreadName>true</includeThreadName>
                <includeMDC>true</includeMDC>
                <includeLoggerName>true</includeLoggerName>
                <includeContextName>true</includeContextName>
                <includeMessage>true</includeMessage>

                <includeFormattedMessage>true</includeFormattedMessage>
                <includeExceptionInMessage>true</includeExceptionInMessage>
                <includeException>true</includeException>

                <serviceContext>
                    <service>EXT-LOG</service>
                </serviceContext>
            </layout>
        </encoder>
    </appender>

<!--    Loggers-->
    <root level="INFO" name="info-log">
        <appender-ref ref="LOCAL_EXTERNAL_DEP"/>
    </root>

    <logger name="com.example.test.service" level="INFO" additivity="false">
        <appender-ref ref="LOCAL_APP" />
    </logger>
</configuration>

RestController代码 #

@RestController
public class TestServiceController {

     @PostMapping("/evaluate")
     public Response evaluate(@RequestBody Request request) {
          UUID transactionId = UUID.randomUUID();
          Logger.info("Starting transaction: ", transactionId);
          MDC.put("transactionId", transactionId.toString());
          //Some java code here (Only simple things)
          Logger.info("This is the mid of controller");
          //Some java code here (Only simple things)
          Logger.info("End of trx, cleaning MDC context : ", transactionId);
          MDC.clear();

          return transaction.getResponse();
     }
}

初步推测 #

Cloud Logging会丢弃短时间内并行执行产生的高相似度日志，希望得到对应的问题排查方向。

内容的提问来源于stack exchange，提问作者user17346823