Add OpenTelemetry Span Creation for Spring Security Filters and Expose as Configurable Property

[Seifenn]

Expected Behavior

I want to track the execution of Spring Security filters and send the trace data to Jaeger using OpenTelemetry instrumentation. After enabling logging.level.org.springframework.security=TRACE in my application.properties, I was able to see the execution traces of each security filter inside my request.

Current Behavior

After enabling logging.level.org.springframework.security=TRACE, I am able to see the logs for every security filter executed inside the request. However, when I examine the FilterChainProxy class to trace the log message, I find that the class VirtualFilterChain contains the log message when a filter is executed. This log message is not linked with any trace or span information, and I am unable to send the traces to Jaeger for internal filters. Therefore the modification need to be made inside the FilterChainProxy class to add support for sending the spans directly if the property is enable since they are default filters.

Context

How has this issue affected you?

I am trying to trace the security filters’ execution for better observability of the request lifecycle, especially for security filters. Without proper tracing for these internal filters, I cannot send meaningful telemetry data to Jaeger. I have also created an issue in the open-telemetry/opentelemetry-java-instrumentation#12730 since the two are related the addition will be inside spring security and enabled in opentelemtry out of the box instrumentation.

What are you trying to accomplish?

I would like to add OpenTelemetry span creation at the point where filters are executed, and make this behavior configurable via a property (e.g., instrumentation.spring.security) to enable tracing for internal filters. This will help me trace the execution of the security filters with each request sent.

What other alternatives have you considered?

I considered modifiying the filterchain to add a filter before the default filters execution that will send this span but i will be modifying the default chain which is not a good approach since everyone who will want to intrument spring security will need this feature. I also used spring AOP to track methods execution inside org.springframework.security.web.FilterChainProxy but this approach cause me problems with native compilation and dont give informations about the filters executed.

Are you aware of any workarounds?

A workaround I found was adding the span creation directly within the VirtualFilterChain class where the logs are generated. However, this solution is not ideal because it requires custom modifications to the Spring Security classes.

Proposed Solution

I propose adding span creation inside the VirtualFilterChain class, where the log message for each filter execution is triggered. Additionally, I recommend exposing this feature as a configuration property, such as instrumentation.spring.security, which would allow users to enable or disable tracing for internal Spring Security filters.

Original Class Code :

This is the code of the virtual filter chain where the logs that i get about the filter executed is sent i want to create same logic but with the span for each filter executed being sent.

/**
 * Internal {@code FilterChain} implementation that is used to pass a request through
 * the additional internal list of filters which match the request.
 */
private static final class VirtualFilterChain implements FilterChain {

	private final FilterChain originalChain;

	private final List<Filter> additionalFilters;

	private final int size;

	private int currentPosition = 0;

	private VirtualFilterChain(FilterChain chain, List<Filter> additionalFilters) {
		this.originalChain = chain;
		this.additionalFilters = additionalFilters;
		this.size = additionalFilters.size();
	}

	@Override
	public void doFilter(ServletRequest request, ServletResponse response) throws IOException, ServletException {
		if (this.currentPosition == this.size) {
			this.originalChain.doFilter(request, response);
			return;
		}
		this.currentPosition++;
		Filter nextFilter = this.additionalFilters.get(this.currentPosition - 1);
		if (logger.isTraceEnabled()) {
			String name = nextFilter.getClass().getSimpleName();
			logger.trace(LogMessage.format("Invoking %s (%d/%d)", name, this.currentPosition, this.size));
		}
		nextFilter.doFilter(request, response, this);
	}

With span addition

private static final class VirtualFilterChain implements FilterChain {

private static final Tracer tracer = GlobalOpenTelemetry.getTracer("spring-security");

@Value("${otel.instrumentation.spring-security.enabled:false}") 
private boolean tracingEnabled;

private final FilterChain originalChain;
private final List<Filter> additionalFilters;
private final int size;
private int currentPosition = 0;

private VirtualFilterChain(FilterChain chain, List<Filter> additionalFilters) {
    this.originalChain = chain;
    this.additionalFilters = additionalFilters;
    this.size = additionalFilters.size();
}

@Override
public void doFilter(ServletRequest request, ServletResponse response) throws IOException, ServletException {
    if (this.currentPosition == this.size) {
        this.originalChain.doFilter(request, response);
        return;
    }

    this.currentPosition++;
    Filter nextFilter = this.additionalFilters.get(this.currentPosition - 1);

    // Only create a span if tracing is enabled
    Span span = null;
    if (tracingEnabled) {
        String filterName = nextFilter.getClass().getSimpleName();
        span = tracer.spanBuilder("Filter: " + filterName)
                .setAttribute("filter.name", filterName)
                .setAttribute("filter.position", this.currentPosition)
                .startSpan();
    }

     if (logger.isTraceEnabled()) {
            logger.trace("Invoking {} ({}/{})", filterName, this.currentPosition, this.size);
        }

    try (Scope scope = (span != null) ? span.makeCurrent() : null) {
        nextFilter.doFilter(request, response, this);
    } catch (Exception e) {
        if (span != null) {
            span.recordException(e);
        }
        throw e;
    } finally {
        if (span != null) {
            span.end();
        }
    }
}
}

The addition of the spans should look like this with maybe a different config for the tracer but now we will have a span created for each request and the spans will be created if the parameter otel.instrumentation.spring-security.enabled is set to true.