Increased timeout for Zipkin Server start

This commit is contained in:
Marcin Grzejszczak
2016-12-27 10:52:27 +01:00
parent a28cc4600f
commit 5df50bf4ea
2 changed files with 62 additions and 86 deletions

View File

@@ -42,6 +42,8 @@ could set `logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG
NOTE: Set `spring.application.name=bar` (for instance) to see the
service name as well as the trace and span ids.
:branch: master
Spring Cloud Sleuth implements a distributed tracing solution for http://cloud.spring.io[Spring Cloud].
=== Terminology
@@ -77,7 +79,7 @@ the start and stop of a request are:
Visualization of what *Span* and *Trace* will look in a system together with the Zipkin annotations:
image::{github-raw}/docs/src/main/asciidoc/images/trace-id.png[Trace Info propagation]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/trace-id.png[Trace Info propagation]
Each color of a note signifies a span (7 spans - from *A* to *G*). If you have such information in the note:
@@ -91,7 +93,7 @@ That means that the current span has *Trace-Id* set to *X*, *Span-Id* set to *D*
This is how the visualization of the parent / child relationship of spans would look like:
image::{github-raw}/docs/src/main/asciidoc/images/parents.png[Parent child relationship]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/parents.png[Parent child relationship]
=== Purpose
@@ -99,49 +101,66 @@ In the following sections the example from the image above will be taken into co
==== Distributed tracing with Zipkin
Altogether there are *10 spans* . If you go to traces in Zipkin you will see this number:
Altogether there are *7 spans* . If you go to traces in Zipkin you will see this number in the second trace:
image::{github-raw}/docs/src/main/asciidoc/images/zipkin-traces.png[Traces]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/zipkin-traces.png[Traces]
However if you pick a particular trace then you will see *7 spans*:
However if you pick a particular trace then you will see *4 spans*:
image::{github-raw}/docs/src/main/asciidoc/images/zipkin-ui.png[Traces Info propagation]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/zipkin-ui.png[Traces Info propagation]
NOTE: When picking a particular trace you will see merged spans. That means that if there were 2 spans sent to
Zipkin with Server Received and Server Sent / Client Received and Client Sent
annotations then they will presented as a single span.
In the image depicting the visualization of what *Span* and *Trace* is you can see 20
colorful labels. How does it happen that in Zipkin 10 spans are received?
Why is there a difference between the 7 and 4 spans in this case?
- 2 span *A* labels signify span started and closed. Upon closing a single span is sent to Zipkin.
- 4 span *B* labels are in fact are single span with 4 annotations. However this span is composed of
two separate instances. One sent from service 1 and one from service 2. So in fact two span instances will be sent
to Zipkin and merged there.
- 2 span *C* labels signify span started and closed. Upon closing a single span is sent to Zipkin.
- 4 span *B* labels are in fact are single span with 4 annotations. However this span is composed of
two separate instances. One sent from service 2 and one from service 3. So in fact two span instances will be sent
to Zipkin and merged there.
- 2 span *E* labels signify span started and closed. Upon closing a single span is sent to Zipkin.
- 4 span *B* labels are in fact are single span with 4 annotations. However this span is composed of
two separate instances. One sent from service 2 and one from service 4. So in fact two span instances will be sent
to Zipkin and merged there.
- 2 span *G* labels signify span started and closed. Upon closing a single span is sent to Zipkin.
- 2 spans come from `http:/start` span. It has the Server Received (SR) and Server Sent (SS) annotations.
- 2 spans come from the RPC call from `service1` to `service2` to the `http:/foo` endpoint. It has the Client Sent (CS)
and Client Received (CR) annotations on `service1` side. It also has Server Received (SR) and Server Sent (SS) annotations
on the `service2` side. Physically there are 2 spans but they form 1 logical span related to an RPC call.
- 2 spans come from the RPC call from `service2` to `service3` to the `http:/bar` endpoint. It has the Client Sent (CS)
and Client Received (CR) annotations on `service2` side. It also has Server Received (SR) and Server Sent (SS) annotations
on the `service3` side. Physically there are 2 spans but they form 1 logical span related to an RPC call.
- 2 spans come from the RPC call from `service2` to `service4` to the `http:/baz` endpoint. It has the Client Sent (CS)
and Client Received (CR) annotations on `service2` side. It also has Server Received (SR) and Server Sent (SS) annotations
on the `service4` side. Physically there are 2 spans but they form 1 logical span related to an RPC call.
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.
So if we count the physical spans we have *1* from `http:/start`, *2* from `service1` calling `service2`, *2* form `service2`
calling `service3` and *2* from `service2` calling `service4`. Altogether *7* spans.
Logically we see the information of *Total Spans: 4* because we have *1* span related to the incoming request
to `service1` and *3* spans related to RPC calls.
==== Visualizing errors
Zipkin allows you to visualize errors in your trace. When an exception was thrown and wasn't caught then we're
setting proper tags on the span which Zipkin can properly colorize. You could see in the list of traces one
trace that was in red color. That's because there was an exception thrown.
If you click that trace then you'll see a similar picture
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/zipkin-error-traces.png[Error Traces]
Then if you click on one of the spans you'll see the following
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/zipkin-error-trace-screenshot.png[Error Traces Info propagation]
As you can see you can easily see the reason for an error and the whole stacktrace related to it.
==== Live examples
.Click Pivotal Web Services icon to see it live!
[caption="Click Pivotal Web Services icon to see it live!"]
image::{github-raw}/docs/src/main/asciidoc/images/pws.png["Zipkin deployed on Pivotal Web Services", link="http://docssleuth-zipkin-server.cfapps.io/", width=150, height=74]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/pws.png["Zipkin deployed on Pivotal Web Services", link="http://docssleuth-zipkin-server.cfapps.io/", width=150, height=74]
The dependency graph in Zipkin would look like this:
image::{github-raw}/docs/src/main/asciidoc/images/dependencies.png[Dependencies]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/dependencies.png[Dependencies]
.Click Pivotal Web Services icon to see it live!
[caption="Click Pivotal Web Services icon to see it live!"]
image::{github-raw}/docs/src/main/asciidoc/images/pws.png["Zipkin deployed on Pivotal Web Services", link="http://docssleuth-zipkin-server.cfapps.io/dependency", width=150, height=74]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/pws.png["Zipkin deployed on Pivotal Web Services", link="http://docssleuth-zipkin-server.cfapps.io/dependency", width=150, height=74]
==== Log correlation
@@ -161,7 +180,7 @@ If you're using a log aggregating tool like https://www.elastic.co/products/kiba
http://www.splunk.com/[Splunk] etc. you can order the events that took place. An example of
Kibana would look like this:
image::{github-raw}/docs/src/main/asciidoc/images/kibana.png[Log correlation with Kibana]
image::https://raw.githubusercontent.com/spring-cloud/spring-cloud-sleuth/{branch}/docs/src/main/asciidoc/images/kibana.png[Log correlation with Kibana]
If you want to use https://www.elastic.co/guide/en/logstash/current/index.html[Logstash] here is the Grok pattern for Logstash:
@@ -194,7 +213,7 @@ we're passing the dependencies in the `groupId:artifactId:version` notation.
*Logback setup*
Below you can find an example of a Logback configuration (file named `https://github.com/spring-cloud-samples/sleuth-documentation-apps/blob/master/service1/src/main/resources/logback-spring.xml[logback-spring.xml]`) that:
Below you can find an example of a Logback configuration (file named https://github.com/spring-cloud-samples/sleuth-documentation-apps/blob/master/service1/src/main/resources/logback-spring.xml[logback-spring.xml]) that:
- logs information from the application in a JSON format to a `build/${spring.application.name}.json` file
- has commented out two additional appenders - console and standard log file
@@ -211,13 +230,13 @@ Below you can find an example of a Logback configuration (file named `https://gi
<property name="LOG_FILE" value="${BUILD_FOLDER:-build}/${springAppName}"/>
<property name="CONSOLE_LOG_PATTERN"
value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr([${springAppName:-},%X{X-B3-TraceId:-},%X{X-B3-SpanId:-},%X{X-Span-Export:-}]){yellow} %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"/>
value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr([${springAppName:-},%X{X-B3-TraceId:-},%X{X-B3-SpanId:-},%X{X-B3-ParentSpanId:-},%X{X-Span-Export:-}]){yellow} %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"/>
<!-- Appender to log to console -->
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<!-- Minimum logging level to be presented in the console logs-->
<level>INFO</level>
<level>DEBUG</level>
</filter>
<encoder>
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
@@ -257,6 +276,7 @@ Below you can find an example of a Logback configuration (file named `https://gi
"service": "${springAppName:-}",
"trace": "%X{X-B3-TraceId:-}",
"span": "%X{X-B3-SpanId:-}",
"parent": "%X{X-B3-ParentSpanId:-}",
"exportable": "%X{X-Span-Export:-}",
"pid": "${PID:-}",
"thread": "%thread",
@@ -270,7 +290,7 @@ Below you can find an example of a Logback configuration (file named `https://gi
</appender>
<root level="INFO">
<!--<appender-ref ref="console"/>-->
<appender-ref ref="console"/>
<appender-ref ref="logstash"/>
<!--<appender-ref ref="flatfile"/>-->
</root>
@@ -280,50 +300,6 @@ Below you can find an example of a Logback configuration (file named `https://gi
NOTE: If you're using a custom `logback-spring.xml` then you have to pass the `spring.application.name` in
`bootstrap` instead of `application` property file. Otherwise your custom logback file won't read the property properly.
==== Propagating Span Context
The span context is the state that must get propagated to any child Spans across process boundaries.
Part of the Span Context is the Baggage. The trace and span IDs are a required part of the span context.
Baggage is an optional part.
Baggage is a set of key:value pairs stored in the span context. Baggage travels together with the trace
and is attached to every span. Spring Cloud Sleuth will understand that a header is baggage related if the HTTP
header is prefixed with `baggage-` and for messaging it starts with `baggage_`.
IMPORTANT: There's currently no limitation of the count or size of baggage items. However, keep in mind that
too many can decrease system throughput or increase RPC latency. In extreme cases, it could crash the app due
to exceeding transport-level message or header capacity.
Example of setting baggage on a span:
[source,java]
----
Span initialSpan = this.tracer.createSpan("span");
initialSpan.setBaggageItem("foo", "bar");
----
===== Baggage vs. Span Tags
Baggage travels with the trace (i.e. every child span contains the baggage of its parent). Zipkin has no knowledge of
baggage and will not even receive that information.
Tags are attached to a specific span - they are presented for that particular span only. However you
can search by tag to find the trace, where there exists a span having the searched tag value.
If you want to be able to lookup a span based on baggage, you should add corresponding entry as a tag in the root span.
[source,java]
----
@Autowired Tracer tracer;
Span span = tracer.getCurrentSpan();
String baggageKey = "key";
String baggageValue = "foo";
span.setBaggageItem(baggageKey, baggageValue);
tracer.addTag(baggageKey, baggageValue);
----
=== Adding to the project
==== Only Sleuth (log correlation)
@@ -339,7 +315,7 @@ the `spring-cloud-starter-sleuth` module to your project.
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-dependencies</artifactId>
<version>Camden.RELEASE</version>
<version>Brixton.RELEASE</version>
<type>pom</type>
<scope>import</scope>
</dependency>
@@ -360,7 +336,7 @@ the Spring BOM
----
dependencyManagement { <1>
imports {
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Camden.RELEASE"
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Brixton.RELEASE"
}
}
@@ -384,7 +360,7 @@ If you want both Sleuth and Zipkin just add the `spring-cloud-starter-zipkin` de
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-dependencies</artifactId>
<version>Camden.RELEASE</version>
<version>Brixton.RELEASE</version>
<type>pom</type>
<scope>import</scope>
</dependency>
@@ -405,7 +381,7 @@ the Spring BOM
----
dependencyManagement { <1>
imports {
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Camden.RELEASE"
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Brixton.RELEASE"
}
}
@@ -429,7 +405,7 @@ If you want both Sleuth and Zipkin just add the `spring-cloud-sleuth-stream` dep
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-dependencies</artifactId>
<version>Camden.RELEASE</version>
<version>Brixton.RELEASE</version>
<type>pom</type>
<scope>import</scope>
</dependency>
@@ -461,7 +437,7 @@ the Spring BOM
----
dependencyManagement { <1>
imports {
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Camden.RELEASE"
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Brixton.RELEASE"
}
}
@@ -491,7 +467,7 @@ dependency
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-dependencies</artifactId>
<version>Camden.RELEASE</version>
<version>Brixton.RELEASE</version>
<type>pom</type>
<scope>import</scope>
</dependency>
@@ -523,7 +499,7 @@ the Spring BOM
----
dependencyManagement { <1>
imports {
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Camden.RELEASE"
mavenBom "org.springframework.cloud:spring-cloud-dependencies:Brixton.RELEASE"
}
}

View File

@@ -15,6 +15,8 @@
*/
package integration;
import static java.util.concurrent.TimeUnit.SECONDS;
import java.util.Collections;
import java.util.Random;
@@ -40,8 +42,6 @@ import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;
import example.ZipkinStreamServerApplication;
import tools.AbstractIntegrationTest;
import static java.util.concurrent.TimeUnit.SECONDS;
@RunWith(SpringJUnit4ClassRunner.class)
@SpringBootTest(classes = { TestSupportBinderAutoConfiguration.class, ZipkinStreamServerApplication.class },
webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
@@ -60,7 +60,7 @@ public class ZipkinStreamTests extends AbstractIntegrationTest {
@Before
public void setup() {
await().atMost(5, SECONDS).until(zipkinServerIsUp());
await().atMost(10, SECONDS).until(zipkinServerIsUp());
}
@Test