Spring-cloud-sleuth: NullPointerException in TraceWebAspect.markRequestForSpanClosing(TraceWebAspect.java:147)

[renannprado]

Using version 1.2.1.RELEASE

Filter that is causing problems:

public class AuthenticationFilter extends GenericFilterBean {
    @Override
    public void doFilter(final ServletRequest servletRequest, final ServletResponse servletResponse, final FilterChain chain) throws IOException, ServletException {
        if (servletRequest.getAttribute(AUTHENTICATED_USER_REQ_ATTRIBUTE) == null) {
            final HttpServletResponse response = (HttpServletResponse) servletResponse;
            response.sendError(HttpStatus.UNAUTHORIZED.value());
        }

        chain.doFilter(servletRequest, servletResponse);
    }
}

Basically using the response.sendError(HttpStatus.UNAUTHORIZED.value()); causes the error. If I, for example, use response.setStatus, the NullPointerException doesn't happen

[marcingrzejszczak]

Thanks for the issue. I've added an NPE check.

[renannprado]

Great!
When will the next version be released?

[marcingrzejszczak]

we've released a version 2 days ago so it will take a while... Until then you can try to register the changed version of the aspect with @Primary (it seems to be working).

@Bean @Primary TraceWebAspect traceWebAspectNewVersion(Tracer tracer, SpanNamer spanNamer, TraceKeys traceKeys) {
        return new TraceWebAspect(tracer, spanNamer, traceKeys) {
            @Override public Object markRequestForSpanClosing(ProceedingJoinPoint pjp,
                    HttpServletRequest request, HttpServletResponse response,
                    Object handler, Exception ex) throws Throwable {
Span currentSpan = this.tracer.getCurrentSpan();
        try {
            if (currentSpan != null && !currentSpan.tags().containsKey(Span.SPAN_ERROR_TAG_NAME)) {
                this.tracer.addTag(Span.SPAN_ERROR_TAG_NAME, ExceptionUtils.getExceptionMessage(ex));
            }
            return pjp.proceed();
        } finally {
            if (log.isDebugEnabled()) {
                log.debug("Marking span " + currentSpan + " for closure by Trace Filter");
            }
            request.setAttribute(TraceFilter.TRACE_CLOSE_SPAN_REQUEST_ATTR, true);
        }
            }
        };
    }

[renannprado]

Unfortunatelly it doesn't work... there are variables that are private.

[marcingrzejszczak]

Ah true. It's enough to do some copy pasting ;)

@Bean @Primary TraceWebAspect traceWebAspectNewVersion(final Tracer tracer, SpanNamer spanNamer, TraceKeys traceKeys) {
        return new TraceWebAspect(tracer, spanNamer, traceKeys) {
            @Override public Object markRequestForSpanClosing(ProceedingJoinPoint pjp,
                    HttpServletRequest request, HttpServletResponse response,
                    Object handler, Exception ex) throws Throwable {
                Span currentSpan = tracer.getCurrentSpan();
                try {
                    if (currentSpan != null && !currentSpan.tags().containsKey(Span.SPAN_ERROR_TAG_NAME)) {
                        tracer.addTag(Span.SPAN_ERROR_TAG_NAME, ExceptionUtils.getExceptionMessage(ex));
                    }
                    return pjp.proceed();
                } finally {
                    request.setAttribute(TraceFilter.class.getName()
                            + ".CLOSE_SPAN", true);
                }
            }
        };
    }

[renannprado]

The tracer is also private... I guess I can't avoid copying the whole class?

[marcingrzejszczak]

tracer comes from the autowired bean in the parameter. @Bean @Primary TraceWebAspect traceWebAspectNewVersion(final Tracer tracer, SpanNamer spanNamer, TraceKeys traceKeys) { .

[renannprado]

True... my bad. Thanks a lot!

[renannprado]

I found another thing... not sure if it is an issue, but even using @Primary, another TraceWebAspect is still being instantiated by the library

[marcingrzejszczak]

Yeah but it shouldn't be used. At least from my fast verification, it seems so ;)

[renannprado]

I've put a breakpoint there, both are being called

[marcingrzejszczak]

That's unfortunate then :/ You can try to call the method

@Bean @Primary TraceWebAspect traceWebAspect(final Tracer tracer, SpanNamer spanNamer, TraceKeys traceKeys) {
        return new TraceWebAspect(tracer, spanNamer, traceKeys) { ... }

Then, theoretically, it should override the bean from another method. But as you can see we're trying to hack around this issue unfortunately :/

[renannprado]

I tried that and also didn't work :(
What's the consequences in this case (besides performance)?

[marcingrzejszczak]

I have one more idea. What you can is

public class AuthenticationFilter extends GenericFilterBean {

   private final Tracer tracer;

   AuthenticationFilter(Tracer tracer) {
      this.tracer = tracer;
   }

    @Override
    public void doFilter(final ServletRequest servletRequest, final ServletResponse servletResponse, final FilterChain chain) throws IOException, ServletException {
        if (servletRequest.getAttribute(AUTHENTICATED_USER_REQ_ATTRIBUTE) == null) {
            final HttpServletResponse response = (HttpServletResponse) servletResponse;
           if (!tracer.isTracing()) {
          tracer.createSpan("error"); 
           }
            response.sendError(HttpStatus.UNAUTHORIZED.value());
        }

        chain.doFilter(servletRequest, servletResponse);
    }
}

Try starting a span before sending the error. I think the span will be closed for you but try running this a couple of times to see if you don't get any Sleuth related exceptions.

[renannprado]

That worked! Thanks a lot!

[marcingrzejszczak]

No problem!