Spring Cloud — Sleuth

Ahmet Cokgungordu
7 min readOct 26, 2019

--

Bu yazımda, Spring Cloud Sleuth’u inceleyeceğiz. Spring Sleuth, herhangi bir uygulamada birden fazla servisten oluşan bir sistemdeki logları geliştirmek için kullanılan çok güçlü bir araçtır.

Hepimiz mutlaka scheduled task, multi-threaded işlemler veya karmaşık web istekleriyle karşılaşmışızdır. Genellikle loglama mekanizması kullanılsa dahi tek bir request oluşturmak için arkada yapılan işlemlerin birbiriyle olan log ilişkilendirmesini yapmak zordur.

Bir hata oluştuğu zaman, bu karmaşık işlemlerin içinde hatayı bulmak, çok zor ve hatta bazen imkansız bir hale gelebiliyor. Genellikle çözüm olarak loglama esnasında her metoda unique bir kimlik id verilir ve takip bu şekilde sağlanır.

İşte bu karmaşıklığa çözüm olarak Spring Sleuth kütüphanesi kullanılmaktadır. Sleuth kütüphanesi, requestler, threadler veya joblar için logların takip edilmesini mümkün kılar. Sleuth, loglamayı kullanarak sorunları izlemeye ve tanılamaya yardımcı olmak için Logback ve SLF4J gibi log sistemleriyle unique id kullanarak kolayca bütünleşir.

Şimdi Sleuth’un nasıl çalıştığına göz atalım.

Bağımlılıklar

Yeni bir Spring Boot web projesi oluşturarak aşağıdaki bağımlılığı pom.xml dosyamıza ekliyoruz.

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

Böylece uygulamamız Spring Boot ile çalışır ve her bir kayıt için parent pom versiyonlarını sağlar. spring-cloud-starter-sleuth bağımlılığının en son sürümünü burada bulabilirsiniz. Tüm pomu görmek için Github’daki projeyi inceleyebilirsiniz.

Buna ek olarak, Sleuth’a uygulamanın loglarını tanımlaması talimatını verecek bir uygulama adı ekleyelim.

application.properties dosyasını aşağıdaki satırı ekleyerek uygulama adını belirtiyoruz.

spring.application.name=Sleuth Test Application

Sleuth Yapılandırmaları

Sleuth birçok durum için logları geliştirici yeteneğe sahiptir. 2.0.0 sürümünden başlayarak, Spring Cloud Sleuth, uygulamamıza gelen her web isteğine unique id ekleyen Brave kütüphanesini kullanır. Bunun yanında, Spring ekibi bu unique idleri, thread içerisinde paylaşmak için gerekli yapıyı da eklemiştir.

Trace, bir uygulamada tek bir request veya tetiklenen bir job gibi düşünülebilir. Bu yapıda bir requestteki tüm adımlar aynı traceId’ye sahip olacaktır.

Spans ise, bir request veya job’ın bölümleri olarak düşünülebilir. Bir trace, her biri request’in belirli bölümüne denk gelen çok sayıda spans’ten oluşabilir. Trace ve span id’ler kullanılarak, uygulamamızın bir request’i tam olarak ne zaman ve nerede process ettiğini belirleyebiliriz. Bu sayede uygulama loglarımızı okumamız çok daha kolaylaşmaktadır.

Şimdi örnekler ile bu yetenekleri tek bir uygulamada ele alacağız.

Basit Bir Web İsteğinin Loglanması

Öncelikle, içerisinde Get metodu bulunan bir Rest Controller sınıfı oluşturacağız.

@RestController
public class SleuthController {

@GetMapping(“/”)
public String helloAhmet() {
logger.info(“Merhaba Ahmet”);
return “ok”;
}
}

Uygulamamızı çalıştıralım ve “http://localhost:8080” request’ini çağıralım. Aşağıdaki gibi bir log bastığını göreceğiz.

2019–10–10 02:38:28.264 INFO 
[Sleuth Test Application,0b3fb6314e30f734,0b3fb6314e30f734,false] 12716
— — [nio-8080-exec-1] c.b.spring.session.SleuthController : Merhaba Ahmet

Yukarıdaki log, başlangıçtaki kısım haricinde normal bir log gibi görünür. Bu Spring Sleuth’un eklediği temel bilgilerdir. Bu veri formatı aşağıdaki gibidir.

[applicationName, traceId, spanId, export]

  • ApplicationName application.properties dosyasında belirlediğimiz isimlendirmedir. Aynı uygulamanın birden çok instance’ından logları toplamak, birleştirmek için kullanılabilir.
  • TraceId TraceId tek bir request, job veya action için atanan bir id’dir. Örnek olarak, her bir kullanıcı tarafından başlatılan web isteğine karşılık gelecektir.
  • SpanId — Tek bir iş birimini izler. Birden çok adımdan oluşan bir istek düşünüldüğünde, her adımın kendine ait bir spanId’si vardır. Varsayılan olarak, herhangi bir uygulama akışı aynı traceId ve spanId ile başlayacaktır.
  • Export — Bu özellik, bu log kaydının Zipkin gibi bir log toplayıcı mekanizmaya aktarılıp aktarılmadığını gösterir. Zipkin, Sleuth tarafından oluşturulan logların analizinde önemli rol oynamaktadır. Bu konu daha sonra detaylı olarak incelenecektir.

Şimdiye kadar Sleuth kütüphanesinin faydaları hakkında genel bir bilginiz olmuştur. Bir başka örnekle detaylı incelemeye devam edelim.

Servis Katmanı Kullanarak Web İsteğinin Loglanması

Yine en basit haliyle aşağıdaki gibi @Service anotasyonu kullanarak yeni bir servis sınıfımızı oluşturuyoruz.

@Service
public class SleepService {

public void sleep() {
Thread.sleep(1000L);
logger.info(“Sleep is over”);
}
}

Şimdi bu hizmetimizi yazmış olduğumuz Controller sınıfımıza bağlayacağız. Sonrasında dışarıdan gelen bir isteği, yazdığımız servis katmanına yönlendireceğiz.

@Autowired
private SleepService sleepService;

@GetMapping(“/sleep”)
public String helloSleep() throws InterruptedException {
logger.info(“Sleep”);
sleepService.sleep();
return “success”;
}

Son olarak, uygulamızı başlatıp “/sleep” isteğini çağırıyoruz. Aşağıdaki gibi bir log çıktısı göreceksiniz.

2019–10–10 03:38:28.264 INFO 
[Sleuth Test Application,9036d5b9b77a5ea7,9036d5b9b77a5ea7,false] 12516
— — [nio-8080-exec-3] c.b.spring.session.SleuthController : Sleep
2019–10–10 03:38:29.264 INFO
[Sleuth Test Application,9036d5b9b77a5ea7,9036d5b9b77a5ea7,false] 12516
— — [nio-8080-exec-3] c.baeldung.spring.session.SleepService : Sleep is over

Mesajlar farklı iki sınıftan gelse de, log traceId ve spanId çıktılarının aynı olduğunu göreceksiniz. Bu, bir istek sırasında log içinde isteği bulmayı kolaylaştırır.

Bu varsayılan bir işlemdir ve bir istek tek bir id alır. Ancak gereklilik durumunda manuel müdahale edebiliriz. Şimdi manuel değiştirilebilir bir örneği inceleyelim.

Manuel SpanId Ekleme Yöntemi

Başlangıçta yeni bir istek için mapping oluşturalım.

@GetMapping(“/new-sleep”)
public String helloNewSleep() {
logger.info(“New Sleep”);
sleepService.newSleep();
return “success”;
}

Şimdi servisimize yeni metodu ekleyelim.

@Autowired
private Tracer tracer;
public void helloNewSleep() throws InterruptedException {
logger.info(“I’m in the original sleep”);

Span newSleep = tracer.nextSpan().name(“newSleep”).start();
try (SpanInScope ws = tracer.withSpanInScope(newSleep.start())) {
Thread.sleep(1000L);
logger.info(“I’m in the new sleep”);
} finally {
newSleep.finish();
}

logger.info(“I’m in the original sleep”);
}

Yukarıda Tracer adında yeni bir sınıfı ekledik. Tracer sınıfı, en başta Spring Sleuth tarafından oluşturulur ve sınıfımıza enjekte edip kullanabiliriz.

Trace manuel olarak başlatılmalı ve durdurulmalıdır. Bunu yapmak için, metot içerisinde oluşturulan span bir try-finally bloğu içerisinde kullanılır ve metot çıkışında span kapatıldığından emin olunur.

Uygulamayı yeniden başlatıyoruz ve “http://localhost:8080/new-sleep” endpointini çağırıyoruz. Aşağıdaki gibi bir çıktı alacaksınız.

2019–10–11 23:05:54.542 
INFO [Sleuth Test Application,ffe8b9cdebbbbade,ffe8b9cdebbbbade,false] 12516
— — [nio-8080-exec-6] c.b.spring.session.SleuthController : New Sleep
2019–10–11 23:05:54.542
INFO [Sleuth Test Application,ffe8b9cdebbbbade,ffe8b9cdebbbbade,false] 12516
— — [nio-8080-exec-6] c.baeldung.spring.session.SleepService :
I’m in the original sleep
2019–10–11 23:05:55.542
INFO [Sleuth Test Application,ffe8b9cdebbbbade,252a01e706fee9c2,false] 12516
— — [nio-8080-exec-6] c.baeldung.spring.session.SleepService :
I’m in the new sleep
2019–10–11 23:05:55.542
INFO [Sleuth Test Application,ffe8b9cdebbbbade,ffe8b9cdebbbbade,false] 12516
— — [nio-8080-exec-6] c.baeldung.spring.session.SleepService :
I’m in the original sleep

Üçüncü log satırında traceId’nin aynı olduğunu ve yeni bir spanId üretildiğini görebiliyoruz. Bu tarz kullanımlar ile kod blogunu farklı bölümlere ayırarak daha detaylı log izlemesi yapılabilir.

Şimdi Sleuth’un thread içinde nasıl kullanıldığına bakalım.

Thread İçerisinde Kullanım

Sleuth kullanımı için önce thread pool yapılandırmasını yapalım.

@Configuration
public class ThreadConfig {

@Autowired
private BeanFactory beanFactory;

@Bean
public Executor executor() {
ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
threadPoolTaskExecutor.setCorePoolSize(1);
threadPoolTaskExecutor.setMaxPoolSize(1);
threadPoolTaskExecutor.initialize();

return new LazyTraceExecutor(beanFactory, threadPoolTaskExecutor);
}
}

LazyTraceExecutor kullanılmasının belirtilmesi önemlidir. Bu sınıf Sleuth kütüphanesinden gelmektedir. Böylece traceId’lerimizin yeni threadler içine yayılması ve yeni spanId yaratılması sağlanmış olur.

Bu yarattığımız executor beani yeni endpointimize bağlayarak sonuçlarına bakalım.

@Autowired
private Executor executor;

@GetMapping(“/new-thread”)
public String helloSleuthNewThread() {
logger.info(“New Thread”);
Runnable runnable = () -> {
try {
Thread.sleep(1000L);
} catch (InterruptedException e) {
e.printStackTrace();
}
logger.info(“I’m inside the new thread — with a new span”);
};
executor.execute(runnable);

logger.info(“I’m done — with the original span”);
return “success”;
}

Yukarıdaki anlatılanları eklediysek uygulamamızı yeniden başlatabiliriz. “http://localhost:8080/new-thread" endpointine istek atalım. Aşağıdaki gibi bir log gelecektir.

2019–10–10 21:18:15.949 
INFO [Sleuth Test Application,6a789607c363434d,6a789607c363434d,false] 12516
— — [nio-8080-exec-9] c.b.spring.session.SleuthController : New Thread
2019–10–10 21:18:15.950
INFO [Sleuth Test Application,6a789607c363434d,6a789607c363434d,false] 12516
— — [nio-8080-exec-9] c.b.spring.session.SleuthController :
I’m done — with the original span
2019–10–10 21:18:16.953
INFO [Sleuth Test Application,6a789607c363434d,a680e3b613ddfe3ddea,false] 12516
— — [lTaskExecutor-1] c.b.spring.session.SleuthController :
I’m inside the new thread — with a new span

Önceki örnekte de olduğu gibi, tüm logların aynı traceId’ye sahip olduğunu görebiliriz. Ancak runnable loguna baktığımızda, o thread içinde yapılan iş için yeni bir spanId verildiğini görebiliriz. Thread içinde yeni bir spanId verilmesini LazyTraceExecutor sağlamıştır. Eğer LazyTraceExecutor yerine standart Executor kullanmış olsaydık, thread içinde yapılan iş için spanId değerini aynı görecektik.

Sırada Sleuth’un @Async kullanımında nasıl olduğunun incelenmesi var.

Sleuth’un @Async Desteği

Async desteği eklemek için ThreadConfig sınıfımıza aşağıdaki eklemeleri yapıyoruz.

@Configuration
@EnableAsync
public class ThreadConfig extends AsyncConfigurerSupport {

//...
@Override
public Executor getAsyncExecutor() {
ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
threadPoolTaskExecutor.setCorePoolSize(1);
threadPoolTaskExecutor.setMaxPoolSize(1);
threadPoolTaskExecutor.initialize();

return new LazyTraceExecutor(beanFactory, threadPoolTaskExecutor);
}
}

Async executor belirtmek için ThreadConfig sınıfımıza AsyncConfigurerSupport sınıfını extends edeceğiz. Sleuth’u Async ile kullanmak için LazyTraceExecutor kullanıldığına dikkat edelim. Ayrıca ThreadConfig sınıfımıza @EnableAsync ekleyerek Async kullanımını etkinleştiriyoruz. Şimdi Service sınıfımıza yeni bir Async metod ekliyoruz.

@Async
public void asyncMethod() {
logger.info(“Start Async Method”);
Thread.sleep(2000L);
logger.info(“End Async Method”);
}

Async metodunu Controller sınıfımızda kullanacak şekilde yeni bir endpoint açıyoruz.

@GetMapping(“/async”)
public String helloSleuthAsync() {
logger.info(“Before Async Method Call”);
sleepService.asyncMethod();
logger.info(“After Async Method Call”);

return “success”;
}

Uygulamamızı yeniden başlatıp “http://localhost:8080/aysnc" endpointine istek gönderiyoruz. Aşağıdaki gibi log çıktısını göreceğiz.

2019–10–10 21:30:40.621 
INFO [Sleuth Test Application,f819c18777ff153f,f819c18777ff153f,false] 10072
— — [nio-8080-exec-2] c.b.spring.session.SleuthController :
Before Async Method Call
2019–10–10 21:30:40.622
INFO [Sleuth Test Application,f819c18777ff153f,f819c18777ff153f,false] 10072
— — [nio-8080-exec-2] c.b.spring.session.SleuthController :
After Async Method Call
2019–10–10 21:30:40.622
INFO [Sleuth Test Application,f819c18777ff153f,3f8a9fdca0976a9e,false] 10072
— — [lTaskExecutor-1] c.baeldung.spring.session.SleepService :
Start Async Method
2019–10–10 21:30:41.622
INFO [Sleuth Test Application,f819c18777ff153f,3f8a9fdca0976a9e,false] 10072
— — [lTaskExecutor-1] c.baeldung.spring.session.SleepService :
End Async Method

Burada thread örneğine benzer şekilde, Sleuth’un traceId’yi async metoduna geçirdiğini ve yeni bir spanId oluşturduğunu görüyoruz.

Şimdi ise zamanlanmış görevlerde nasıl kullanılacağını inceleyelim.

@Scheduled ile Sleuth Kullanımı

Son olarak, Sleuth kütüphanesinin @Scheduled metodlarla nasıl çalıştığına bakalım. Bunu yapmak için, öncelikle zamanlanmış görevleri @EnableScheduling anotasyonu ile etkinleştirmemiz gerekiyor.

@Configuration
@EnableAsync
@EnableScheduling
public class ThreadConfig extends AsyncConfigurerSupport
implements SchedulingConfigurer {

//...

@Override
public void configureTasks(ScheduledTaskRegistrar scheduledTaskRegistrar) {
scheduledTaskRegistrar.setScheduler(schedulingExecutor());
}

@Bean(destroyMethod = “shutdown”)
public Executor schedulingExecutor() {
return Executors.newScheduledThreadPool(1);
}
}

SchedulingConfigurer interface kullandığımızı ve configureTasks metodunu override ettiğimize dikkat edelim. Ayrıca @EnableScheduling ile zamanlanmış görevleri etkinleştirmiş olduk.

Artık zamanlanmış görevlerimiz için yeni bir Service sınıfı oluşturup bir metod ekliyoruz.

@Service
public class SchedulingService {

private Logger logger = LoggerFactory.getLogger(this.getClass());

@Autowired
private SleepService sleepService;

@Scheduled(fixedDelay = 30000)
public void scheduledWork() throws InterruptedException {
logger.info(“Start some work from the scheduled task”);
sleepService.asyncMethod();
logger.info(“End work from scheduled task”);
}
}

Bu sınıfta, 30 saniye sabit aralıklarla çalışmasını sağladığımız bir zamanlanmış görev oluşturduk. Şimdi uygulamamızı yeniden başlatıp görevin tetiklenmesini bekleyelim ve loga bakalım.

2019–10–10 21:30:58.866 
INFO [Sleuth Test Application,5dea3605f8dfea22,5dea3605f8dfea22,false] 10072
— — [pool-1-thread-1] c.b.spring.session.SchedulingService :
Start some work from the scheduled task
2019–10–10 21:30:58.866
INFO [Sleuth Test Application,5dea3605f8dfea22,5dea3605f8dfea22,false] 10072
— — [pool-1-thread-1] c.b.spring.session.SchedulingService :
End work from scheduled task

Burada Sleuth’un zamanlanmış görevimiz için yeni traceId ve spanId yarattığını görebiliriz. Bir görev her çalışmasında, varsayılan olarak kendi traceId ve spanId’sini alır.

Şimdiye kadar Spring Sleuth kütüphanesinin tek bir web uygulaması içindeki çeşitli durumlarda nasıl kullanıldığını gördük. Bu teknolojiyi, bir request birden çok iş parçacığını kapsadığında bile loglarımızı tek bir request ile kolayca ilişkilendirmek için kullanabiliriz.

Spring Cloud Sleuth’un multi-threaded ortamda hata incelerken bize nasıl yardımcı olabileceğini gördük. Her bir işlemi ve bir bölümdeki her adımı tanımlayarak, uygulamamızdaki karmaşık işlemlerin analizini daha kolay yapmamızı sağlamış olduk.

Spring Sleuth kütüphanesi neredeyse her projemizde kullanmamız gereken kritik bir bağımlılıktır. Spring Sleuth’a entegre olmak işlerimize muazzam bir değer katacaktır.

Sleuth’un özellikleri sadece bunlarla sınırlı değildir. RestTemplate kullanarak, RabbitMQ ve Redis tarafından kullanılan mesajlaşma protokolleri arasında ve Zuul gibi kütüphane aracılığıyla dağıtılmış sistemlerde log izlemeyi de destekler.

--

--