How to send Lombok @Slf4j logs and System.out.println() logs to Open Telemetry through Micrometer

56 Views Asked by At

My current setup is: a Spring Boot app (version 3.1.5) with Micrometer, sending traces, metrics and (ideally) all logs to an otel/opentelemetry-collector-contrib Docker container.

Everything seems working, except I cannot manage to make the Spring Boot app send logs to the OTEL collector.

As I couldn't find very clear instructions on how to do this, I'm just putting things together, for example from these two and others: https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/7723 https://github.com/ff-sdesai/distributed-tracing-spring/blob/ee36dcd78ce9c0b517355642af3c5e0b8b6d67d0/spring-cloud-sleuth-otel-slf4j/src/main/resources/logback.xml#L17

and hope that it works... but it doesn't, therefore I'm here:

application.yml

spring:
  output:
    ansi:
      enabled: always
  (...)
# Micrometer tracing
management:
  tracing:
    sampling:
      probability: 1.0
  otlp:
    tracing:
      endpoint: http://localhost:4318/v1/traces
    metrics:
      export:
        url: http://localhost:4318/v1/metrics
  endpoints:
    web:
      exposure:
        include: "*"
  (...)
logging:
  pattern:
    console: '[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} [%X{traceId}] [%X{spanId}] - %msg%n'
    level: '%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]'

logback.xml

<configuration>
  <property name="LOGS" value="./logs"/>

  <appender name="Console"
    class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <Pattern>
        %black(%d{ISO8601}) %highlight(%-5level) [%blue(%t)] %yellow(%C{1}): trace_id: %X{traceId}
        span_id: %X{spanId} %msg%n%throwable
      </Pattern>
    </layout>
  </appender>

  <appender name="RollingFile"
    class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOGS}/up-user-service.log</file>
    <encoder
      class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
      <Pattern>%d %p %C{1} [%t] %m%n</Pattern>
    </encoder>

    <rollingPolicy
      class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <!-- rollover daily and when the file reaches 10 MegaBytes -->
      <fileNamePattern>${LOGS}/archived/up-user-service-%d{yyyy-MM-dd}.%i.log
      </fileNamePattern>
      <timeBasedFileNamingAndTriggeringPolicy
        class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <maxFileSize>10MB</maxFileSize>
      </timeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
  </appender>

  <!-- io.opentelemetry.instrumentation.logback.v1_0.OpenTelemetryAppender -->
  <appender name="OTEL"
    class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender"></appender>

  <!-- LOG everything at INFO level -->
  <root level="info">
    <appender-ref ref="RollingFile"/>
    <appender-ref ref="Console"/>
  </root>

  <logger name="com.uplight.upuserservice" level="trace" additivity="false">
    <appender-ref ref="RollingFile"/>
    <appender-ref ref="Console"/>
    <appender-ref ref="OTEL"/>
  </logger>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <!-- encoders are assigned the type
    ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} serviceName: %X{serviceName} requestId: %X{requestId} trace_id: %X{traceId} span_id: %X{spanId} - %msg%n</pattern>
    </encoder>
  </appender>

  <appender name="OTEL" class="io.opentelemetry.instrumentation.logback.v1_0.OpenTelemetryAppender">
    <appender-ref ref="STDOUT" />
  </appender>

  <root level="INFO">
    <appender-ref ref="STDOUT" />
  </root>

</configuration>

pom.xml

(...)
<dependency>
      <groupId>org.springframework.boot</groupId>
      <artifactId>spring-boot-starter-actuator</artifactId>
    </dependency>

    <!-- Adds the Tracing API -->
    <dependency>
      <groupId>io.micrometer</groupId>
      <artifactId>micrometer-tracing</artifactId>
    </dependency>

    <!-- Adds the Tracer Implementation -->
    <dependency>
      <groupId>io.micrometer</groupId>
      <artifactId>micrometer-tracing-bridge-otel</artifactId>
    </dependency>

    <!-- Adds an exporter to store the traces -->
    <dependency>
      <groupId>io.opentelemetry</groupId>
      <artifactId>opentelemetry-exporter-otlp</artifactId>
    </dependency>

    <dependency>
      <groupId>io.opentelemetry.instrumentation</groupId>
      <artifactId>opentelemetry-logback-appender-1.0</artifactId>
      <version>2.1.0-alpha</version>
      <scope>runtime</scope>
    </dependency>

    <dependency>
      <groupId>io.opentelemetry</groupId>
      <artifactId>opentelemetry-exporter-otlp-logs</artifactId>
      <version>1.26.0-alpha</version>
    </dependency>

    <dependency>
      <groupId>io.opentelemetry.instrumentation</groupId>
      <artifactId>opentelemetry-logback-1.0</artifactId>
      <version>1.9.2-alpha</version>
      <scope>runtime</scope>
    </dependency>
(...)

NOTE: I wondering if this issue is related but not caused by the lack of spanid and traceid in some logs. None of them have them, except for example when I log inside a custom span. This is an example of class trying different features including creating spans:

TestApi.java

@Slf4j
@RestController
class TestApi {

    @Autowired
    private ObservationRegistry observationRegistry;

    @Autowired
    private Tracer tracer;

    @Autowired
    private MeterRegistry meterRegistry;

    @GetMapping("test")
    void test() {
        System.out.println("### MY TEST ###");
        log.info("@@@@@ TEST LOMBOK LOGGER @@@@@");
    }

    @GetMapping("exception")
    void exception() throws Exception {
        throw new Exception("CUSTOM EXCEPTION");
    }

    @GetMapping("custom_span") // WORKS
    void customSpan() throws Exception {
        Observation observation = Observation.createNotStarted("my-custom-operation", this.observationRegistry);
        observation.lowCardinalityKeyValue("my-tag", "my-value");
        observation.observe(() -> {
            System.out.println("### HOW LONG DID IT TAKE? ###");
            log.info("@@@@@ HOW LONG DID IT TAKE? @@@@@");
        });
    }

    // So, what is Baggage? The spec defines a standard HTTP header to propagate the application-defined properties associated with a distributed request.
    @GetMapping("custom_baggage")
    void customBaggage() {
        try (BaggageInScope scope = this.tracer.createBaggageInScope("my-baggage-key", "my-baggage-value")) {
            System.out.println("### IS IT BAGGAGING? ###");
            log.info("@@@@@ IS IT BAGGAGING? @@@@@");
            log.info("Contains the following baggage {}", tracer.getAllBaggage());
        }
    }

    @GetMapping("custom_metric")
    void customMetric() { // TODO: TO BE TESTED WITH A COMPATIBLE METRIC UI
        log.info("CREATING CUSTOM METRIC");
        List<Integer> list = new ArrayList<>();
        meterRegistry.gauge("list.size", Tags.empty(), list.size());
        list.add(1);
        list.add(2);
        list.add(3);
    }
}

config.yaml

receivers:
  otlp:
    protocols:
      grpc:
        endpoint:  0.0.0.0:4317
      http:
        endpoint: 0.0.0.0:4318

processors:

exporters:
  logging:
    loglevel: debug

  jaeger:
    endpoint: jaeger-service:14250
    tls:
      insecure: true

service:
  pipelines:
    traces:
      receivers: [otlp]
      exporters: [logging, jaeger]
    metrics:
      receivers: [otlp]
      exporters: [logging]
    logs:
      receivers: [ otlp ]
      exporters: [logging] 
0

There are 0 best solutions below