akkinoc / logback-access-spring-boot-starter

Spring Boot Starter for Logback-access.
Apache License 2.0
193 stars 32 forks source link

Micrometer Tracing Support for Access Logs #114

Open DarkAtra opened 2 years ago

DarkAtra commented 2 years ago

Describe the problem you'd like to have solved

I am currently using Micrometer Tracing and noticed that there is no traceId in the access log. I think adding this would be a great feature as it allows you to match your app log and access log entries, which can make troubleshooting easier.

Describe the solution you'd like

Open for discussion, i'd be down to contribute once we found the desired solution ^^

akkinoc commented 2 years ago

Thank you for your suggestion!

I'm sorry, I'm not fluent in Spring Cloud Sleuth. How can I retrieve traceId /spanId?

If you implement your own custom Appender, you may be able to solve it early.

DarkAtra commented 2 years ago

Hey @akkinoc, sorry for the delayed response, i was on vacation ^^

Spring Cloud allows you to retrieve the TraceContext from the HttpServletRequest via:

final ServletRequestAttributes requestAttributes = new ServletRequestAttributes(request);
final TraceContext traceContext = (TraceContext) requestAttributes.getAttribute("org.springframework.cloud.sleuth.TraceContext", RequestAttributes.SCOPE_REQUEST);

// get tracing ids via
traceContext.traceId();
traceContext.spanId();
traceContext.parentId();

I'm not sure how it works when using the reactive stack though.

We're currently using custom DynamicConverter implementations to resolve tracing ids the same way as i decribed above. However, that only works with synchronous appenders. I think this is because the TraceContext is scoped to the request and asynchronous appenders can be executed after the request. Thus all request scoped beans would be already gone. I think you'd have to already resolve the tracing ids when the LogbackAccessEvent is created to fix that issue.

akkinoc commented 2 years ago

Thank you for the detailed information!

I created a sample project. https://github.com/akkinoc/try-logback-access-spring-boot-starter-with-sleuth

It worked with the following patch.

  1. Implement a web filter to store the attributes for logging by logback-access-spring-boot-starter.
@WebFilter
public class SleuthAttrsFilter implements Filter {

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        // Stores Spring Cloud Sleuth attributes for logging by logback-access-spring-boot-starter
        TraceContext context = (TraceContext) request.getAttribute(TraceContext.class.getName());
        request.setAttribute(SleuthAttrsFilter.class.getName() + ".traceId", context.traceId());
        request.setAttribute(SleuthAttrsFilter.class.getName() + ".spanId", context.spanId());
        chain.doFilter(request, response);
    }

}
  1. Register the web filter in your application.
@Bean
public FilterRegistrationBean<SleuthAttrsFilter> sleuthAttrsFilter() {
    SleuthAttrsFilter filter = new SleuthAttrsFilter();
    FilterRegistrationBean<SleuthAttrsFilter> bean = new FilterRegistrationBean<>(filter);
    bean.setDispatcherTypes(DispatcherType.FORWARD, DispatcherType.INCLUDE,
            DispatcherType.REQUEST, DispatcherType.ASYNC, DispatcherType.ERROR);
    return bean;
}
  1. Refer to the attributes stored from "logback-access.xml".
<configuration>
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%h %l %u [%t] "%r" %s %b [%reqAttribute{example.SleuthAttrsFilter.traceId}, %reqAttribute{example.SleuthAttrsFilter.spanId}]</pattern>
        </encoder>
    </appender>
    <appender-ref ref="console"/>
</configuration>

Please try this patch 😃

DarkAtra commented 2 years ago

Hello @akkinoc, thank you very much! I'll try the code you suggested next week, but I'm very sure this will work without any issues. Is there any chance that this functionality will be integrated directly in the starter or is it too big of an edge case?

Update: the suggested code works as expected (only for non webflux apps though). Ty again :D

akkinoc commented 2 years ago

Thank you for your reply. I would like to consider supporting this feature in future versions!

DarkAtra commented 10 months ago

I've updated the issue title and description as Spring Cloud Sleuth is no longer maintained and the tracing support has moved to micrometer tracing.

This is an updated version of the custom filter above:

import java.io.IOException;

import org.springframework.lang.Nullable;
import org.springframework.web.filter.OncePerRequestFilter;

import io.micrometer.tracing.Span;
import io.micrometer.tracing.TraceContext;
import io.micrometer.tracing.Tracer;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import lombok.RequiredArgsConstructor;

@RequiredArgsConstructor
public class TracingAttributesFilter extends OncePerRequestFilter {

    @Nullable
    private final Tracer tracer;

    @Override
    protected void doFilterInternal(final HttpServletRequest request, final HttpServletResponse response, final FilterChain chain)
            throws ServletException, IOException {

        if (tracer != null) {
            final Span span = tracer.currentSpan();
            if (span != null) {
                final TraceContext traceContext = span.context();
                if (traceContext != null) {
                    request.setAttribute(TracingAttributesFilter.class.getName() + "traceId", traceContext.traceId());
                    request.setAttribute(TracingAttributesFilter.class.getName() + "spanId", traceContext.spanId());
                    request.setAttribute(TracingAttributesFilter.class.getName() + "parentId", traceContext.parentId());
                }
            }
        }

        chain.doFilter(request, response);
    }
}