log4j2日志时设置Otel Span属性失败排查及替代方案咨询

问题背景 #

业务逻辑中WARN/ERROR级别的日志需要给关联的OpenTelemetry Span标记logging.level属性，以便Collector后续判断是否存储追踪数据。但自定义的OtelAttributeAppender调用setAttribute方法后，Span并未成功添加该属性，怀疑调用时Span已结束。同时尝试通过IDEA启动参数-Dotel.javaagent.logging=application和环境变量OTEL_LOG_LEVEL=FINE/DEBUG开启Otel SDK日志未成功。

检查Span是否已结束的方法 #

• 直接调用Span状态判断方法：在调用setAttribute前后，获取当前Span并调用isRecording()方法。如果返回false，说明Span已经结束或处于不可修改状态，这就是属性设置失败的直接原因。可以直接在代码中添加日志输出这个结果，无需依赖Otel SDK日志：

  Span currentSpan = Span.current();
  boolean isRecording = currentSpan.isRecording();
  log.debug("Span is recording: {}", isRecording);
  if (isRecording) {
      currentSpan.setAttribute("logging.level", "ERROR");
  }
  

• 追踪Span生命周期时间点：在Span的创建/启动和结束节点添加日志，记录Span ID和操作时间。比如使用@WithSpan注解的方法入口/出口，或者手动调用Span.start()/Span.end()的位置，打印类似Span [ID: xxx] started at [时间]和Span [ID: xxx] ended at [时间]的日志，再对比打属性的时间点，就能明确Span是否已结束。
• 修复Otel SDK日志开启问题：
  1. 确保启动参数-Dotel.javaagent.logging=application已正确添加到IDEA的VM options中，而非环境变量。
  2. 调整应用日志框架的配置，将io.opentelemetry包的日志级别设为DEBUG或TRACE。比如在Logback的配置文件中添加：

     <logger name="io.opentelemetry" level="DEBUG" additivity="false">
         <appender-ref ref="YOUR_APPENDER"/>
     </logger>
     

  3. OTEL_LOG_LEVEL的有效值对应Java日志级别：FINE对应DEBUG，FINER对应TRACE，可以尝试直接设置OTEL_LOG_LEVEL=DEBUG。

设置Span属性的替代方案 #

• 在业务逻辑中直接设置属性：不要等到日志Appender阶段，而是在抛出异常或触发WARN/ERROR日志的时机，直接操作当前Span。比如在catch块中：

  try {
      // 业务逻辑
  } catch (Exception e) {
      Span currentSpan = Span.current();
      if (currentSpan.isRecording()) {
          currentSpan.setAttribute("logging.level", "ERROR");
      }
      log.error("业务执行失败", e);
  }
  

• 确保Span上下文正确传递：如果是异步任务场景，要把当前Span的上下文传递到异步线程中，比如使用Context.current().wrap()包装Runnable/Callable，确保异步线程中能获取到活跃的Span：

  Runnable task = Context.current().wrap(() -> {
      // 异步任务逻辑，打日志时Span仍处于活跃状态
      Span currentSpan = Span.current();
      currentSpan.setAttribute("logging.level", "WARN");
      log.warn("异步任务执行警告");
  });
  executorService.submit(task);
  

• 调整Span生命周期：如果是因为Span提前结束导致属性设置失败，检查代码中Span的结束时机，确保在打WARN/ERROR日志之后再调用Span.end()，或者延长Span的生命周期覆盖日志输出阶段。

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