Fixed missing logs for untraced first request

fixes #231

Author: marcingrzejszczak

docs/src/main/asciidoc/images/dependencies.png

@@ -84,6 +84,10 @@ colorful labels. How does it happen that in Zipkin 10 spans are received?
 So 1 span from *A*, 2 spans from *B*, 1 span from *C*, 2 spans from *D*, 1 span from *E*, 2 spans from *F* and 1 from *G*.
 Altogether *10* spans.
 
+The dependency graph in Zipkin would look like this:
+
+image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/master/docs/src/main/asciidoc/images/dependencies.png[Dependencies]
+
 ==== Log correlation
 
 When grepping the logs of those four applications by trace id equal to e.g. `2485ec27856c56f4` one would get the following:

docs/src/main/asciidoc/intro.adoc

@@ -136,10 +136,12 @@ protected void doFilterInternal(HttpServletRequest request,
 				addResponseTags(response, exception);
 				if (spanFromRequest.hasSavedSpan()) {
 					Span parent =  spanFromRequest.getSavedSpan();
-					if (parent != null && parent.isRemote()) {
+					if (parent.isRemote()) {
 						parent.logEvent(Span.SERVER_SEND);
 						this.spanReporter.report(parent);
 					}
+				} else {
+					spanFromRequest.logEvent(Span.SERVER_SEND);
 				}
 				// Double close to clean up the parent (remote span as well)
 				this.tracer.close(spanFromRequest);
@@ -171,6 +173,7 @@ private Span createSpan(HttpServletRequest request,
 			else {
 				spanFromRequest = this.tracer.createSpan(name);
 			}
+			spanFromRequest.logEvent(Span.SERVER_RECV);
 			request.setAttribute(TRACE_REQUEST_ATTR, spanFromRequest);
 		}
 		return spanFromRequest;

spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/TraceFilter.java

@@ -25,7 +25,7 @@
 import org.springframework.web.bind.annotation.RequestMapping;
 import org.springframework.web.bind.annotation.RestController;
 
-import static org.assertj.core.api.BDDAssertions.then;
+import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then;
 import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.asyncDispatch;
 import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status;
 
@@ -61,6 +61,7 @@ public void should_create_and_return_trace_in_HTTP_header() throws Exception {
 		MvcResult mvcResult = whenSentPingWithoutTracingData();
 
 		then(tracingHeaderFrom(mvcResult)).isNotNull();
+		then(TraceFilterIntegrationTests.span).hasLoggedAnEvent(Span.SERVER_RECV).hasLoggedAnEvent(Span.SERVER_SEND);
 	}
 
 	@Test
@@ -71,7 +72,7 @@ public void should_ignore_sampling_the_span_if_uri_matches_management_properties
 	}
 
 	@Test
-	public void when_correlationId_is_sent_should_not_create_a_new_one_but_return_the_existing_one_instead()
+	public void when_traceId_is_sent_should_not_create_a_new_one_but_return_the_existing_one_instead()
 			throws Exception {
 		Long expectedTraceId = new Random().nextLong();
 
@@ -81,7 +82,7 @@ public void when_correlationId_is_sent_should_not_create_a_new_one_but_return_th
 	}
 
 	@Test
-	public void when_correlationId_is_sent_to_async_endpoint_span_is_joined()
+	public void when_traceId_is_sent_to_async_endpoint_span_is_joined()
 			throws Exception {
 		Long expectedTraceId = new Random().nextLong();
 
@@ -115,16 +116,16 @@ private MvcResult whenSentFutureWithTraceId(Long passedTraceId) throws Exception
 		return sendPingWithTraceId("/future", Span.TRACE_ID_NAME, passedTraceId);
 	}
 
-	private MvcResult sendPingWithTraceId(String headerName, Long correlationId)
+	private MvcResult sendPingWithTraceId(String headerName, Long traceId)
 			throws Exception {
-		return sendPingWithTraceId("/ping", headerName, correlationId);
+		return sendPingWithTraceId("/ping", headerName, traceId);
 	}
 
 	private MvcResult sendPingWithTraceId(String path, String headerName,
-			Long correlationId) throws Exception {
+			Long traceId) throws Exception {
 		return this.mockMvc
 				.perform(MockMvcRequestBuilders.get(path).accept(MediaType.TEXT_PLAIN)
-						.header(headerName, Span.idToHex(correlationId))
+						.header(headerName, Span.idToHex(traceId))
 						.header(Span.SPAN_ID_NAME, Span.idToHex(new Random().nextLong())))
 				.andReturn();
 	}