AccessLogAutoConfiguration.java

import org.springframework.boot.context.embedded.EmbeddedServletContainerCustomizer;
import org.springframework.boot.context.embedded.tomcat.TomcatContextCustomizer;
import org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedServletContainerFactory;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

import ch.qos.logback.access.tomcat.LogbackValve;
import ch.qos.logback.core.util.ContextUtil;
import lombok.extern.slf4j.Slf4j;

@Slf4j
@Configuration
public class AccessLogAutoConfiguration {
    @Bean
    public EmbeddedServletContainerCustomizer containerCustomizer(SleuthValve sleuthValve, LogbackValve logbackValve) {
        return container -> {
            if (container instanceof TomcatEmbeddedServletContainerFactory) {
                ((TomcatEmbeddedServletContainerFactory) container)
                        .addContextCustomizers((TomcatContextCustomizer) context -> {
                            context.getPipeline().addValve(sleuthValve);
                            context.getPipeline().addValve(logbackValve);
                        });
            } else {
                log.warn("no access-log auto-configuration for container: {}", container);
            }
        };
    }

    @Bean
    public SleuthValve sleuthValve(Tracer tracer) {
        return new SleuthValve(tracer);
    }

    @Bean
    public LogbackValve logbackValve() {
        LogbackValve logbackValve = new LogbackValve();
        logbackValve.putProperty("HOSTNAME", new ContextUtil(null).safelyGetLocalHostName());
        logbackValve.setFilename("logback-access.xml");
        logbackValve.setQuiet(true);
        return logbackValve;
    }
}

ApplicationTest.java

import static org.assertj.core.api.Assertions.assertThat;
import static org.mockito.Matchers.any;
import static org.mockito.Mockito.spy;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;

import java.io.IOException;
import java.net.InetAddress;
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.Paths;
import java.util.List;

import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.autoconfigure.EnableAutoConfiguration;
import org.springframework.boot.context.embedded.LocalServerPort;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Import;
import org.springframework.http.HttpEntity;
import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpMethod;
import org.springframework.test.context.junit4.SpringRunner;
import org.springframework.web.client.HttpClientErrorException;
import org.springframework.web.client.RestTemplate;

@RunWith(SpringRunner.class)
@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
public class ApplicationTest {
    @LocalServerPort
    private int port;

    @Autowired
    private SleuthValve sleuthValve;

    @Test
    public void testLogAccess() throws Exception {
        whenServerReceivesHttpRequest();
        thenHostnameIsLoggedToAccessLog();

        verify(sleuthValve,times(1)).invoke(any(),any());
    }

    private void thenHostnameIsLoggedToAccessLog() throws IOException {
        String hostname = InetAddress.getLocalHost().getHostName();
        Path logs = Paths.get(System.getProperty("user.dir") + "/target", "logs", "access.log");
        List<String> lines = Files.readAllLines(logs);

        assertThat(lines.size()).describedAs("access log contain one line").isEqualTo(1);

        assertThat(lines.get(0)).describedAs("access log should contain hostname").contains(" " + hostname + " ");
        assertThat(lines.get(0)).describedAs("access log should contain trace").endsWith(" d4bc04106fef10ba");
    }

    private void whenServerReceivesHttpRequest() {
        RestTemplate template = new RestTemplate();

        HttpHeaders headers = new HttpHeaders();
        headers.set("X-B3-TraceId", "d4bc04106fef10ba");

        HttpEntity entity = new HttpEntity(headers);
        try {
            template.exchange("http://localhost:" + port, HttpMethod.GET, entity, String.class);
        } catch (HttpClientErrorException e) {
            if (404 != e.getRawStatusCode()) {
                throw e;
            }
        }
    }

    @Configuration
    @EnableAutoConfiguration
    @Import(AccessLogAutoConfiguration.class)
    static class TestConfig {
        @Bean
        public SleuthValve sleuthValve(Tracer tracer) {
            return spy(new SleuthValve(tracer));
        }
    }
}

logback-access.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <appender name="FILE_ACCESS" class="ch.qos.logback.core.FileAppender">
        <append>false</append>
        <file>target/logs/access.log</file>
        <encoder>
            <pattern>ACCESS ${HOSTNAME} %i{X-B3-TraceId}</pattern>
        </encoder>
    </appender>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>ACCESS ${HOSTNAME} %i{X-B3-TraceId}</pattern>
        </encoder>
    </appender>

    <!--<appender-ref ref="CONSOLE"/>-->
    <appender-ref ref="FILE_ACCESS"/>

</configuration>

SleuthValve.java

import java.io.IOException;

import javax.servlet.ServletException;

import org.apache.catalina.Valve;
import org.apache.catalina.connector.Request;
import org.apache.catalina.connector.Response;
import org.apache.catalina.valves.ValveBase;
import org.apache.tomcat.util.buf.MessageBytes;
import org.apache.tomcat.util.http.MimeHeaders;
import org.springframework.cloud.sleuth.Span;
import org.springframework.cloud.sleuth.Tracer;

import lombok.RequiredArgsConstructor;

@RequiredArgsConstructor
class SleuthValve extends ValveBase {
    private final Tracer tracer;

    @Override
    public void invoke(Request request, Response response) throws IOException, ServletException {

        enrichWithSleuthHeaderWhenMissing(tracer, request);

        Valve next = getNext();
        if (null == next) {
            // no next valve
            return;
        }
        next.invoke(request, response);
    }

    private static void enrichWithSleuthHeaderWhenMissing(final Tracer tracer, final Request request) {
        String header = request.getHeader(Span.TRACE_ID_NAME);
        if (null == header) {

            org.apache.coyote.Request coyoteRequest = request.getCoyoteRequest();
            MimeHeaders mimeHeaders = coyoteRequest.getMimeHeaders();

            Span span = tracer.createSpan("SleuthValve");

            // TODO Regeln für Generierung beachten
            addHeader(mimeHeaders, Span.TRACE_ID_NAME, span.traceIdString());
//            addHeader(mimeHeaders, Span.PARENT_ID_NAME, span.traceIdString());
            addHeader(mimeHeaders, Span.SPAN_ID_NAME, span.traceIdString());
        }
    }

    private static void addHeader(MimeHeaders mimeHeaders, String traceIdName, String value) {
        MessageBytes messageBytes = mimeHeaders.addValue(traceIdName);
        messageBytes.setString(value);
    }
}

SleuthValveTest.java

import static org.assertj.core.api.Assertions.assertThat;

import java.io.IOException;
import java.util.Collections;
import java.util.Random;
import java.util.concurrent.atomic.LongAdder;

import javax.servlet.ServletException;

import org.apache.catalina.connector.Request;
import org.apache.catalina.connector.Response;
import org.apache.catalina.core.StandardContext;
import org.apache.catalina.core.StandardPipeline;
import org.apache.catalina.valves.ValveBase;
import org.apache.tomcat.util.buf.MessageBytes;
import org.apache.tomcat.util.http.MimeHeaders;
import org.junit.Before;
import org.junit.Test;
import org.springframework.cloud.sleuth.DefaultSpanNamer;
import org.springframework.cloud.sleuth.NoOpSpanReporter;
import org.springframework.cloud.sleuth.Span;
import org.springframework.cloud.sleuth.TraceKeys;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.cloud.sleuth.log.NoOpSpanLogger;
import org.springframework.cloud.sleuth.sampler.NeverSampler;
import org.springframework.cloud.sleuth.trace.DefaultTracer;

public class SleuthValveTest {
    private final StandardPipeline pipeline = new StandardPipeline(new StandardContext());
    private final Tracer tracer = createTracer();

    @Before
    public void setUp() throws Exception {
        pipeline.addValve(new SleuthValve(tracer));
    }

    @Test
    public void should_addRequestHeader() throws IOException, ServletException {
        Request request = new Request();
        request.setCoyoteRequest(new org.apache.coyote.Request());

        pipeline.getFirst().invoke(request, new Response());

        assertThat(request.getHeader(Span.TRACE_ID_NAME)).isNotEmpty();
        assertThat(request.getHeader(Span.SPAN_ID_NAME)).isNotEmpty();
        assertThat(request.getHeader(Span.PARENT_ID_NAME)).isNull();
    }

    @Test
    public void should_preserveExistingRequestHeader() throws IOException, ServletException {
        Request request = new Request();
        org.apache.coyote.Request coyoteRequest = new org.apache.coyote.Request();
        request.setCoyoteRequest(coyoteRequest);

        MimeHeaders mimeHeaders = coyoteRequest.getMimeHeaders();

        addHeader(mimeHeaders, Span.TRACE_ID_NAME, "trace");
        addHeader(mimeHeaders, Span.PARENT_ID_NAME, "parent");
        addHeader(mimeHeaders, Span.SPAN_ID_NAME, "span");

        // action
        pipeline.getFirst().invoke(request, new Response());

        assertThat(Collections.list(request.getHeaders(Span.TRACE_ID_NAME))).hasSize(1);
        assertThat(Collections.list(request.getHeaders(Span.SPAN_ID_NAME))).hasSize(1);
        assertThat(Collections.list(request.getHeaders(Span.PARENT_ID_NAME))).hasSize(1);

        assertThat(request.getHeader(Span.TRACE_ID_NAME)).isEqualTo("trace");
        assertThat(request.getHeader(Span.SPAN_ID_NAME)).isEqualTo("span");
        assertThat(request.getHeader(Span.PARENT_ID_NAME)).isEqualTo("parent");
    }

    @Test
    public void should_invokeNextValve() throws IOException, ServletException {
        LongAdder invocationCounter = new LongAdder();
        pipeline.addValve(new ValveBase() {
            @Override
            public void invoke(Request request, Response response) throws IOException, ServletException {
                invocationCounter.increment();
            }
        });

        Request request = new Request();
        request.setCoyoteRequest(new org.apache.coyote.Request());

        //action
        pipeline.getFirst().invoke(request, new Response());

        assertThat(invocationCounter.longValue()).isEqualTo(1);
    }

    private Tracer createTracer() {
        return new DefaultTracer(NeverSampler.INSTANCE, new Random(), new DefaultSpanNamer(), new NoOpSpanLogger(), new NoOpSpanReporter(), new TraceKeys());
    }

    private void addHeader(final MimeHeaders mimeHeaders, final String traceIdName, final String value) {
        MessageBytes messageBytes = mimeHeaders.addValue(traceIdName);
        messageBytes.setString(value);
    }
}