Включение Sleuth замедляет запросы (сильно)

Я использую Spring Cloud Feign и Sleuth с сервером Zipkin. Моя проблема в том, что когда я включаю Sleuth, то любой простой запрос занимает не менее 600 мс. Обратите внимание, что в целях тестирования я установил процент выборки Sleuth на 1.

Могу ли я сделать что-то, чтобы улучшить это?

Вот некоторый лог запроса, который занимает 25 мс без Sleuth и 700 мс со Sleuth. (пользователь звонит /teams, который звонит /cities):

13:46:46.064 [http-nio-8080-exec-3] DEBUG o.s.c.s.instrument.web.TraceFilter - Received a request to uri [/teams] that should not be sampled [false]
13:46:46.064 [http-nio-8080-exec-3] DEBUG o.s.c.s.instrument.web.TraceFilter - No parent span present - creating a new span
13:46:46.065 [http-nio-8080-exec-3] DEBUG o.s.web.servlet.DispatcherServlet - DispatcherServlet with name 'dispatcherServlet' processing GET request for [/teams]
13:46:46.078 [http-nio-8080-exec-3] DEBUG o.s.c.s.i.w.TraceHandlerInterceptor - Handling span [Trace: 99b8ae8aa88157a6, Span: 99b8ae8aa88157a6, Parent: null, exportable:true]
13:46:46.078 [http-nio-8080-exec-3] DEBUG o.s.c.s.i.w.TraceHandlerInterceptor - Adding a method tag with value [getTeams] to a span [Trace: 99b8ae8aa88157a6, Span: 99b8ae8aa88157a6, Parent: null, exportable:true]
13:46:46.078 [http-nio-8080-exec-3] DEBUG o.s.c.s.i.w.TraceHandlerInterceptor - Adding a class tag with value [TeamService] to a span [Trace: 99b8ae8aa88157a6, Span: 99b8ae8aa88157a6, Parent: null, exportable:true]
13:46:46.083 [hystrix-cities-2] DEBUG o.s.c.s.i.h.SleuthHystrixConcurrencyStrategy$HystrixTraceCallable - Continuing span [Trace: 99b8ae8aa88157a6, Span: 99b8ae8aa88157a6, Parent: null, exportable:true]
13:46:46.084 [hystrix-cities-2] DEBUG o.s.c.s.i.w.c.feign.TraceFeignClient - Created new Feign span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true]
13:46:46.084 [hystrix-cities-2] DEBUG o.s.c.s.i.w.c.feign.TraceFeignClient - The modified request equals GET http://localhost:8080/cities HTTP/1.1
X-B3-ParentSpanId: 99b8ae8aa88157a6
X-B3-Sampled: 1
X-B3-TraceId: 99b8ae8aa88157a6
X-Span-Name: http:/cities
X-B3-SpanId: 4cea0c5e2e662ea3

13:46:46.101 [http-nio-8080-exec-5] DEBUG o.s.c.s.instrument.web.TraceFilter - Received a request to uri [/cities] that should not be sampled [false]
13:46:46.101 [http-nio-8080-exec-5] DEBUG o.s.c.s.instrument.web.TraceFilter - Found a parent span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true] in the request
13:46:46.101 [http-nio-8080-exec-5] DEBUG o.s.c.s.instrument.web.TraceFilter - Parent span is [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true]
13:46:46.101 [http-nio-8080-exec-5] DEBUG o.s.b.w.f.OrderedRequestContextFilter - Bound request context to thread: org.apache.catalina.connector.RequestFacade@36324069
13:46:46.101 [http-nio-8080-exec-5] DEBUG o.s.web.servlet.DispatcherServlet - DispatcherServlet with name 'dispatcherServlet' processing GET request for [/cities]
13:46:46.105 [http-nio-8080-exec-5] DEBUG o.s.c.s.i.w.TraceHandlerInterceptor - Handling span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true]
13:46:46.105 [http-nio-8080-exec-5] DEBUG o.s.c.s.i.w.TraceHandlerInterceptor - Adding a method tag with value [getCities] to a span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true]
13:46:46.105 [http-nio-8080-exec-5] DEBUG o.s.c.s.i.w.TraceHandlerInterceptor - Adding a class tag with value [cityService] to a span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true]
13:46:46.106 [http-nio-8080-exec-5] DEBUG o.s.w.s.m.m.a.RequestResponseBodyMethodProcessor - Written [com.citymanager.entity.City@320dc277] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@33bb3f86]
13:46:46.107 [http-nio-8080-exec-5] DEBUG o.s.c.s.instrument.web.TraceFilter - Trying to send the parent span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true] to Zipkin
13:46:46.107 [http-nio-8080-exec-5] DEBUG o.s.c.s.z.ServerPropertiesEndpointLocator - Span will contain serviceName [city-manager]
13:46:46.109 [hystrix-cities-2] DEBUG o.s.c.s.i.w.c.feign.TraceFeignClient - Closing Feign span and logging CR [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true]
13:46:46.109 [hystrix-cities-2] DEBUG o.s.c.s.i.w.c.feign.TraceFeignClient - Closing Feign span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true]
13:46:46.109 [hystrix-cities-2] DEBUG o.s.c.s.z.ServerPropertiesEndpointLocator - Span will contain serviceName [city-manager]
13:46:46.459 [http-nio-8080-exec-5] DEBUG o.s.c.s.instrument.web.TraceFilter - Closing the span [Trace: 99b8ae8aa88157a6, Span: 4cea0c5e2e662ea3, Parent: 99b8ae8aa88157a6, exportable:true] since the response was successful
13:46:46.464 [hystrix-cities-2] DEBUG o.s.w.c.HttpMessageConverterExtractor - Reading [class com.citymanager.entity.City] as "application/json;charset=UTF-8" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@33bb3f86]
13:46:46.465 [hystrix-cities-2] DEBUG o.s.c.s.i.h.SleuthHystrixConcurrencyStrategy$HystrixTraceCallable - Detaching span since it was continued [Trace: 99b8ae8aa88157a6, Span: 99b8ae8aa88157a6, Parent: null, exportable:true]
13:46:46.466 [http-nio-8080-exec-3] DEBUG o.s.w.s.m.m.a.RequestResponseBodyMethodProcessor - Written [com.citymanager.entity.Team@3c35ed9b] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@33bb3f86]
13:46:46.466 [http-nio-8080-exec-3] DEBUG o.s.web.servlet.DispatcherServlet - Successfully completed request
13:46:46.467 [http-nio-8080-exec-3] DEBUG o.s.c.s.instrument.web.TraceFilter - Closing the span [Trace: 99b8ae8aa88157a6, Span: 99b8ae8aa88157a6, Parent: null, exportable:true] since the response was successful
13:46:46.467 [http-nio-8080-exec-3] DEBUG o.s.c.s.z.ServerPropertiesEndpointLocator - Span will contain serviceName [city-manager]
13:46:46.857 [AsyncReporter(org.springframework.cloud.sleuth.zipkin.RestTemplateSender@42519b72)] DEBUG o.s.web.client.RestTemplate - Created POST request for "http://localhost:9411/api/v1/spans"
13:46:46.857 [AsyncReporter(org.springframework.cloud.sleuth.zipkin.RestTemplateSender@42519b72)] DEBUG o.s.web.client.RestTemplate - Setting request Accept header to [text/plain, application/json, application/*+json, */*]
13:46:46.857 [AsyncReporter(org.springframework.cloud.sleuth.zipkin.RestTemplateSender@42519b72)] DEBUG o.s.web.client.RestTemplate - Writing [[B@1aecb2f4] as "application/json" using [org.springframework.http.converter.ByteArrayHttpMessageConverter@4414cc2d]
13:46:46.885 [AsyncReporter(org.springframework.cloud.sleuth.zipkin.RestTemplateSender@42519b72)] DEBUG o.s.web.client.RestTemplate - POST request for "http://localhost:9411/api/v1/spans" resulted in 202 (null)

spring-cloud-sleuth zipkin spring-cloud-feign netflix-feign
person Nicolas    schedule 12.05.2017    source источник

Ответы (3)


arrow_upward
2
arrow_downward

Я полагаю, у вас были проблемы с: org.springframework.cloud.sleuth.zipkin.ServerPropertiesEndpointLocator.

Он использует InetUtils.findFirstNonLoopbackAddress() для определения адреса экземпляра. Метод вызывается синхронно, когда каждый диапазон закрывается (в ZipkinSpanListener#convert). Обходной путь — создать собственный org.springframework.cloud.sleuth.zipkin.EndpointLocator. Вы можете использовать что-то вроде этого:

class CachingEndpointLocator implements EndpointLocator {

    private final Endpoint endpoint;

    CachingEndpointLocator(EndpointLocator delegate) {
      this.endpoint = delegate.local();
    }

    @Override
    public Endpoint local() {
      return endpoint;
    }
  }

И объедините его с одним из существующих EndpointLocators. Вы можете найти их в: org.springframework.cloud.sleuth.zipkin.ZipkinAutoConfiguration.

Эта проблема уже исправлена ​​в сыщике 2.X.X. Где: org.springframework.cloud.sleuth.zipkin2.DefaultEndpointLocator адрес кэш-сервера:

    public DefaultEndpointLocator(Registration registration,
            ServerProperties serverProperties, Environment environment,
            ZipkinProperties zipkinProperties, InetUtils inetUtils) {
        this.registration = registration;
        this.serverProperties = serverProperties;
        this.environment = environment;
        this.zipkinProperties = zipkinProperties;
        this.firstNonLoopbackAddress = findFirstNonLoopbackAddress(inetUtils);
    }
person Rafał Surowiecki    schedule 24.01.2020

arrow_upward
1
arrow_downward

Похоже, вы используете Sleuth с Zipkin через HTTP< /а>. Вы можете попробовать Sleuth с Zipkin через Spring Cloud Stream подход. Сам тест не проводил, но теоретически производительность должна улучшиться.

См. документацию по адресу: https://cloud.spring.io/spring-cloud-sleuth/spring-cloud-sleuth.html#_sleuth_with_zipkin_via_spring_cloud_stream

person burcakulug    schedule 15.05.2017
comment
Thx, я собираюсь попробовать это! - person Nicolas; 19.05.2017

arrow_upward
1
arrow_downward

Интересно, какой метод бенчмаркинга вы выбрали? Какую версию Сыщика вы используете? Кроме того, это единственный тест, который вы делаете? Это на вашем компьютере? Перегрелась ли JVM? Выполняются ли какие-либо другие процессы? Выполнение бенчмаркинга не так просто... Вы можете использовать такие инструменты, как JMH, чтобы сделать это лучше.

Кстати, попробуйте отключить уровень ведения журнала DEBUG и снова проверьте результаты.

Мы проводим тесты производительности Sleuth, и, судя по тому, что мы видим при добавлении Sleuth, задержка увеличивается примерно на 20 мс. Определенно не 600 мс.

person Marcin Grzejszczak    schedule 19.05.2017
comment
Я вызываю тысячу раз первую точку входа с включенным слеутом, а потом без слеута в одном и том же условии: с коэффициентом х30 этого метода достаточно. Я использую Spring Cloud Sleuth 1.2.0, а отладка отключена. Сервер в рабочем состоянии. Ваш тест действительно интересен: вы используете HTTP или Stream? - person Nicolas; 19.05.2017
comment
Что я могу сказать, у нас другие значения, чем у вас, когда мы делаем бенчмаркинг. - person Marcin Grzejszczak; 19.05.2017
comment
Вы можете разместить свой образец где-нибудь, и я могу попробовать его проверить. Вы можете написать об этом в sleuth project, чтобы я не забыл - person Marcin Grzejszczak; 19.05.2017