Spring Cloud Gateway and Sleuth / Zipkin integration

[guerricmerleHUG]

Bug report
spring-cloud-version: Greenwich.M3

We used Spring Cloud Gateway and we starting to integrate Sleuth / Zipkin.

We make this workflow :

client ----> SpringCloudGateway ------> PatientService ------> EpisodeOfCareService

and we have activate DEBUG logs for Sleuth in SC, PS and EOCS apps
logging.level.org.springframework.cloud.sleuth: DEBUG
In Postman or Chrome, we call http://localhost/patient/97005400/with-eds this is pass througth Gateway, PatientService and EpisodeOfCareService

logs are :
Gateway :

2018-11-22 15:11:49.412 DEBUG [gateway-service,,,] 18792 --- [ctor-http-nio-4] o.s.c.s.instrument.web.TraceWebFilter    : Received a request to uri [/patient/97005400/with-eds]
2018-11-22 15:11:49.412 DEBUG [gateway-service,,,] 18792 --- [ctor-http-nio-4] o.s.c.s.instrument.web.TraceWebFilter    : Handled receive of span RealSpan(da30b8233cab261f/da30b8233cab261f)
2018-11-22 15:11:49.471 DEBUG [gateway-service,da30b8233cab261f,da30b8233cab261f,true] 18792 --- [ctor-http-nio-4] o.s.c.s.instrument.web.TraceWebFilter    : Handled send of RealSpan(da30b8233cab261f/da30b8233cab261f)
2018-11-22 15:11:49.818 DEBUG [gateway-service,,,] 18792 --- [ender@1cba0321}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : HTTP POST http://vmlt-00008.hcuge.ch:9411/api/v2/spans
2018-11-22 15:11:49.818 DEBUG [gateway-service,,,] 18792 --- [ender@1cba0321}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : Accept=[text/plain, application/json, application/*+json, */*]
2018-11-22 15:11:49.818 DEBUG [gateway-service,,,] 18792 --- [ender@1cba0321}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : Writing [[B@5c213931] as "application/json"
2018-11-22 15:11:49.823 DEBUG [gateway-service,,,] 18792 --- [ender@1cba0321}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : Response 202 ACCEPTED

PatientService :

2018-11-22 15:11:49.451  INFO [patient-service,6b568740db93adf6,6b568740db93adf6,true] 20456 --- [nio-8001-exec-3] c.h.p.controller.PatientController       : Patient find: id=97005400
2018-11-22 15:11:49.451 DEBUG [patient-service,6b568740db93adf6,6b568740db93adf6,true] 20456 --- [nio-8001-exec-3] c.s.i.w.c.f.TraceLoadBalancerFeignClient : Before send
2018-11-22 15:11:49.452 DEBUG [patient-service,6b568740db93adf6,6b568740db93adf6,true] 20456 --- [nio-8001-exec-3] o.s.c.s.i.w.c.f.LazyTracingFeignClient   : Sending a request via tracing feign client [org.springframework.cloud.sleuth.instrument.web.client.feign.TracingFeignClient@489534aa] and the delegate [feign.Client$Default@50872e76]
2018-11-22 15:11:49.452 DEBUG [patient-service,6b568740db93adf6,6b568740db93adf6,true] 20456 --- [nio-8001-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Handled send of RealSpan(6b568740db93adf6/4077b43e2a74a1ed)
2018-11-22 15:11:49.465 DEBUG [patient-service,6b568740db93adf6,6b568740db93adf6,true] 20456 --- [nio-8001-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Handled receive of RealSpan(6b568740db93adf6/4077b43e2a74a1ed)
2018-11-22 15:11:49.466 DEBUG [patient-service,6b568740db93adf6,6b568740db93adf6,true] 20456 --- [nio-8001-exec-3] c.s.i.w.c.f.TraceLoadBalancerFeignClient : After receive

EpisodeOfCareService :

2018-11-22 15:11:49.461  INFO [episodeofcare-service,6b568740db93adf6,4077b43e2a74a1ed,true] 14664 --- [nio-8101-exec-2] c.h.e.c.EpisodeOfCareController          : Eds find: id=11111111
2018-11-22 15:11:50.127 DEBUG [episodeofcare-service,,,] 14664 --- [ender@4bbf20d1}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : HTTP POST http://vmlt-00008.hcuge.ch:9411/api/v2/spans
2018-11-22 15:11:50.128 DEBUG [episodeofcare-service,,,] 14664 --- [ender@4bbf20d1}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : Accept=[text/plain, application/json, application/*+json, */*]
2018-11-22 15:11:50.128 DEBUG [episodeofcare-service,,,] 14664 --- [ender@4bbf20d1}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : Writing [[B@823c21e] as "application/json"
2018-11-22 15:11:50.134 DEBUG [episodeofcare-service,,,] 14664 --- [ender@4bbf20d1}] o.s.c.s.z.s.ZipkinRestTemplateWrapper    : Response 202 ACCEPTED

As you can see, traceId are différents between Gateway and PatientService/EpisodeOfCareService.
So in Zipkin, there is no correlation :

gateway config :
gateway-build.gradle.txt
application.yml

---
# This default profile is used when running a single instance completely standalone:
spring:
  profiles: default
  application:
    name: gateway-service
  cloud:
    gateway:
      discovery:
        locator:
          enabled: true
      routes:
      - id: patient-service
        uri: lb://patient-service
        predicates:
        - Path=/patient/**
        filters:
        - RewritePath=/patient/(?<segment>.*), /$\{segment}
  zipkin:
    base-url: http://xxxxx:9411
    sender:
      type: web
    service:
      name: ${spring.application.name}  
  sleuth:
    sampler:
      probability: 1     
management:
  endpoints:
    web:
      exposure:
        include: "*"  
  endpoint:
    health:
      show-details: ALWAYS
eureka:
  instance:
    lease-expiration-duration-in-seconds: 10
    lease-renewal-interval-in-seconds: 10    
    instanceId: ${spring.application.name}:${spring.application.instance_id:${random.value}}
  client:
    registerWithEureka: true
    fetchRegistry: true
    prefer-same-zone-eureka: true
    serviceUrl:
      defaultZone: ${EUREKA_CLIENT_SERVICE_URL_DEFAULT_ZONE:http://localhost:8761/eureka}
    registry-fetch-interval-seconds: 10
    region: ${ZONE:us-east-1}
logging:
  level:
    org.springframework.cloud.sleuth: DEBUG

Patient :
patient-build.gradle.txt
application.yml

---
# This default profile is used when running a single instance completely standalone:
spring:
  profiles: default
  zipkin:
    base-url: http://xxxxx:9411
    sender:
      type: web
    service:
      name: ${spring.application.name}  
  sleuth:
    sampler:
      probability: 1 
eureka:  
  instance:
    lease-renewal-interval-in-seconds: 30
    health-check-url-path: /actuator/health
    prefer-ip-address: ${EUREKA_INSTANCE_PREFER_IP_ADDRESS:false}   # forcer l'enregistrement par adresse IP
  client:
    registry-fetch-interval-seconds: 30
    register-with-eureka: true
    fetch-registry: true
    service-url:
      defaultZone: ${EUREKA_CLIENT_SERVICE_URL_DEFAULT_ZONE:http://localhost:8761/eureka}
    region: ${ZONE:us-east-1} 
management:
  endpoints:
    web:
      exposure:
        include: "*"  
  endpoint:
    health:
      show-details: ALWAYS
logging:
  level:
    org.springframework.cloud.sleuth: DEBUG

EOCS :
eds-build.gradle.txt
application.yml (same as patient-service)

What are we doing wrong ?
Thanks for your help

[snmvaughan]

I've run into the same issue. I've been able to verify that the services called by the gateway do not receive any of the X-B3-* headers. I am seeing calls to brave.propagation.B3Propagation.B3Injector.inject(TraceContext traceContext, C carrier). This explains why the PatientService in the example has a separate trace.

I've also noticed that when I'm using StripPrefix=1, the http.path for the span is updated with the stripped path. It feels like the creation of a child span isn't occurring correctly.

[alex0ptr]

We ran into the same issue with Greenwich.M2. Can also confirm on Greenwich.M3.
We used httpbin.org/headers as upstream. The headers are definitely missing.

application.yml:

spring:
  sleuth:
    enabled: true
    sampler.probability: 1
  zipkin:
    enabled: true
    base-url: replace_me

[RostislavReznichenko]

Can confirm on Greenwich.RC2
logger_name reactor.netty.http.server.AccessLog doesn't have traceId

[marcingrzejszczak]

We are blocked by reactor/reactor-netty#558

[marcingrzejszczak]

@spencergibb suggested to work this around in Sleuth via the Gateway interfaces. It's been done via ec60f3a . Can anyone wait for the snapshots to be built and confirm that indeed everything is working fine? I double checked it in the Brewery and it seems to be working fine

[RostislavReznichenko]

I'll check and answer as soon as snapshot build will be ready.
2.1.0.BUILD-SNAPSHOT/ 25-Jul-2018 09:18

[marcingrzejszczak]

Awesome. Give it 3 more minutes and the snapshots should be fully uploaded