当我将 Zipkin 添加到 Sleuth 时，性能会降低 8200%

Question

我提出此查询是因为看到另一个没有令人满意的答案的查询（并阅读了不要在答案或评论中提出其他问题的建议）。该参考是Enabling Sleuth slows requests down (a lot)

我的问题类似。我没有使用 Feign。我正在使用以下内容：

1. 独立邮递员致电我的服务
2. 名为 LniProxy 的 spring-boot 应用程序通过 Spring RestTemplate 调用 Arango 数据库
3. 一个本地 zipkin 服务器到 http post spans。

我正在使用 spring-cloud-sleuth、logback 和 zipkin。 当我删除 zipkin pom 参考时

<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-zipkin</artifactId> 

性能非常快。但是放回去后，性能很差。

在日志中将我的日志级别从 INFO 更改为 DEBUG 会将非 zipkin 调用从 701ms 更改为 1051ms。 添加 zipkin http 将时间从 1051 毫秒更改为大约 53 秒。 在代码中，我对我的服务进行了一次调用，该服务又对 arango 数据库进行了 303 次调用（通过其 REST 接口）。

我正在使用 spring.cloud.starter-sleuth 和 logstash-logback-encoder。本身没有性能问题，只有当我添加 spring-cloud-starter-zipkin 时，性能才会下降。 我在 docker 实例中的本地 pc 上运行 zipkin，并将我的服务作为独立应用程序（spring boot）从 eclipse 中运行。 Arango 在我的本地电脑上作为服务运行。 我的控制器的单元测试方法（使用 mockito 模拟 mvc 调用）通常在没有 zipkin 的情况下每个需要 0.3 到 0.5 秒，在启用 zipkin 时每个最终需要大约 16 秒。 Zipkin UI 报告所有调用，调用的总和大致是 Postman 报告的调用的全部时间。

Application 类在顶部看起来像这样：

@SpringBootApplication
@EnableSwagger2
@EnableAutoConfiguration(exclude={DataSourceAutoConfiguration.class})
public class Application extends SpringBootServletInitializer {

    @Bean
    public Sampler defaultSampler() {
        return new AlwaysSampler();
    }

    @Bean
    public RestTemplate restTemplate() {
        return new RestTemplate();
    }
    //...
}

没有 zipkin 引用的日志文件的结尾如下所示：

2017-07-12 10:43:10.764 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 >> "{"query":"FOR n IN network FILTER n._key == '1176300' FOR e IN networkEdges FILTER e._from == n._id && e.relationship == 'composition' FOR n2 IN network FILTER e._to == n2._id RETURN {child : n2,edge : e}","count":false,"batchSize":10,"ttl":10}"
2017-07-12 10:43:10.765 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 << "HTTP/1.1 201 Created[\r][\n]"
2017-07-12 10:43:10.765 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 << "Server: ArangoDB[\r][\n]"
2017-07-12 10:43:10.765 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 << "Connection: Keep-Alive[\r][\n]"
2017-07-12 10:43:10.765 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 << "Content-Type: application/json; charset=utf-8[\r][\n]"
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 << "Content-Length: 223[\r][\n]"
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 << "[\r][\n]"
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.wire                     : http-outgoing-0 << "{"result":[],"hasMore":false,"cached":false,"extra":{"stats":{"writesExecuted":0,"writesIgnored":0,"scannedFull":0,"scannedIndex":1,"filtered":0,"executionTime":4.990100860595703e-4},"warnings":[]},"error":false,"code":201}"
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.headers                  : http-outgoing-0 << HTTP/1.1 201 Created
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.headers                  : http-outgoing-0 << Server: ArangoDB
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.headers                  : http-outgoing-0 << Connection: Keep-Alive
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.headers                  : http-outgoing-0 << Content-Type: application/json; charset=utf-8
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] org.apache.http.headers                  : http-outgoing-0 << Content-Length: 223
2017-07-12 10:43:10.766 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] o.a.http.impl.execchain.MainClientExec   : Connection can be kept alive indefinitely
2017-07-12 10:43:10.767 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] h.i.c.PoolingHttpClientConnectionManager : Connection [id: 0][route: {}->http://localhost:8529] can be kept alive indefinitely
2017-07-12 10:43:10.767 DEBUG [LniProxy,cfa3eadd0eaa074c,86a81ebae0d1a5df,true] 6960 --- [nio-8090-exec-8] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 0][route: {}->http://localhost:8529][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 10]

使用 zipkin 参考，它看起来像这样：

2017-07-12 10:46:18.217 DEBUG [LniProxy,4e849f3b63c73179,068a8ea6dd096488,true] 14432 --- [nio-8090-exec-2] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 0][route: {}->http://localhost:8529][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 10]
2017-07-12 10:46:18.617 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] o.a.h.client.protocol.RequestAddCookies  : CookieSpec selected: default
2017-07-12 10:46:18.618 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] o.a.h.client.protocol.RequestAuthCache   : Re-using cached 'basic' auth scheme for http://localhost:8529
2017-07-12 10:46:18.618 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] o.a.h.client.protocol.RequestAuthCache   : No credentials for preemptive authentication
2017-07-12 10:46:18.618 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] h.i.c.PoolingHttpClientConnectionManager : Connection request: [route: {}->http://localhost:8529][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 10]
2017-07-12 10:46:18.618 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] h.i.c.PoolingHttpClientConnectionManager : Connection leased: [id: 0][route: {}->http://localhost:8529][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 10]
2017-07-12 10:46:18.618 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] o.a.http.impl.execchain.MainClientExec   : Executing request POST /_db/lni/_api/cursor HTTP/1.1
2017-07-12 10:46:18.618 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] o.a.http.impl.execchain.MainClientExec   : Proxy auth state: UNCHALLENGED

删除了一些日志以适应 30k 字符的限制

2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.wire                     : http-outgoing-0 << "HTTP/1.1 201 Created[\r][\n]"
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.wire                     : http-outgoing-0 << "Server: ArangoDB[\r][\n]"
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.wire                     : http-outgoing-0 << "Connection: Keep-Alive[\r][\n]"
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.wire                     : http-outgoing-0 << "Content-Type: application/json; charset=utf-8[\r][\n]"
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.wire                     : http-outgoing-0 << "Content-Length: 223[\r][\n]"
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.wire                     : http-outgoing-0 << "[\r][\n]"
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.wire                     : http-outgoing-0 << "{"result":[],"hasMore":false,"cached":false,"extra":{"stats":{"writesExecuted":0,"writesIgnored":0,"scannedFull":0,"scannedIndex":1,"filtered":0,"executionTime":5.009174346923828e-4},"warnings":[]},"error":false,"code":201}"
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.headers                  : http-outgoing-0 << HTTP/1.1 201 Created
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.headers                  : http-outgoing-0 << Server: ArangoDB
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.headers                  : http-outgoing-0 << Connection: Keep-Alive
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.headers                  : http-outgoing-0 << Content-Type: application/json; charset=utf-8
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] org.apache.http.headers                  : http-outgoing-0 << Content-Length: 223
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] o.a.http.impl.execchain.MainClientExec   : Connection can be kept alive indefinitely
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] h.i.c.PoolingHttpClientConnectionManager : Connection [id: 0][route: {}->http://localhost:8529] can be kept alive indefinitely
2017-07-12 10:46:18.620 DEBUG [LniProxy,4e849f3b63c73179,7a3998bf127b2daf,true] 14432 --- [nio-8090-exec-2] h.i.c.PoolingHttpClientConnectionManager : Connection released: [id: 0][route: {}->http://localhost:8529][total kept alive: 1; route allocated: 1 of 5; total allocated: 1 of 10]

Answer 1

查看文档中的采样间隔：

在分布式跟踪中，数据量可能非常高，因此采样可能很重要（您通常不需要导出所有跨度来很好地了解正在发生的事情）。 Spring Cloud Sleuth 有一个 Sampler 策略，您可以实现该策略来控制采样算法。采样器不会阻止生成跨度（相关）ID，但它们会阻止附加和导出标签和事件。默认情况下，如果跨度已处于活动状态，您将获得一个继续跟踪的策略，但新的策略始终标记为不可导出。如果您的所有应用程序都使用此采样器运行，您将在日志中看到跟踪，但在任何远程存储中都看不到。对于测试默认值通常就足够了，如果您只使用日志（例如使用 ELK 聚合器），这可能就是您所需要的。如果您要将 span 数据导出到 Zipkin 或 Spring Cloud Stream，还有一个 AlwaysSampler 可以导出所有内容，还有一个 PercentageBasedSampler 可以对固定部分的 span 进行采样。

http://cloud.spring.io/spring-cloud-sleuth/spring-cloud-sleuth.html#_sampling