1. 概要

この記事では、 Spring Cloud Sleuth を紹介します。これは、あらゆるアプリケーション、特に複数のサービスで構成されるシステムでログを強化するための強力なツールです。

この記事では、マイクロサービス全体ではなく、モノリスアプリケーションでSleuthを使用することに焦点を当てます。

私たちは皆、スケジュールされたタスク、マルチスレッド操作、または複雑なWeb要求の問題を診断しようとしたという不幸な経験をしました。 多くの場合、ロギングがある場合でも、単一のリクエストを作成するためにどのアクションを相互に関連付ける必要があるかを判断するのは困難です。

これにより、複雑なアクションの診断が非常に困難になるか、不可能になる可能性があります。 多くの場合、ログを識別するためにリクエスト内の各メソッドに一意のIDを渡すなどの解決策が得られます。

入ってくるSleuth。 このライブラリを使用すると、特定のジョブ、スレッド、または要求に関連するログを識別できます。 Sleuthは、LogbackSLF4Jなどのロギングフレームワークと簡単に統合して、ログを使用して問題を追跡および診断するのに役立つ一意の識別子を追加します。

それがどのように機能するかを見てみましょう。

2. 設定

まず、お気に入りのIDEで Spring Boot Webプロジェクトを作成し、この依存関係をpom.xmlファイルに追加します。

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

このアプリケーションはSpringBoot で実行され、親pomは各エントリのバージョンを提供します。 この依存関係の最新バージョンは、spring-cloud-starter-sleuthにあります。 POM全体を確認するには、Githubでプロジェクトを確認してください。

さらに、アプリケーション名を追加して、Sleuthにこのアプリケーションのログを識別するように指示しましょう。

application.properties ファイルに次の行を追加します:

spring.application.name=Baeldung Sleuth Tutorial

3. スルース構成

Sleuth は、多くの状況でログを拡張できます。 バージョン2.0.0以降、SpringCloudSleuthはBraveをトレースライブラリとして使用し、アプリケーションに入力される各Webリクエストに一意のIDを追加します。 さらに、Springチームは、スレッドの境界を越えてこれらのIDを共有するためのサポートを追加しました。

トレースは、アプリケーションでトリガーされる単一のリクエストまたはジョブのように考えることができます。 そのリクエストのさまざまなステップはすべて、アプリケーションとスレッドの境界を越えても、同じtraceIdを持ちます。

一方、スパンは、ジョブまたは要求のセクションと考えることができます。 単一のトレースは、リクエストの特定のステップまたはセクションにそれぞれ相関する複数のスパンで構成できます。 トレースIDとスパンIDを使用すると、アプリケーションがリクエストを処理するときに、アプリケーションがいつどこにあるかを正確に特定できます。 ログの読み取りがはるかに簡単になります。

この例では、これらの機能を1つのアプリケーションで調べます。

3.1. シンプルなWebリクエスト

まず、操作するエントリポイントとなるコントローラークラスを作成しましょう。

@RestController
public class SleuthController {

    @GetMapping("/")
    public String helloSleuth() {
        logger.info("Hello Sleuth");
        return "success";
    }
}

アプリケーションを実行して、「http:// localhost:8080」に移動しましょう。 次のような出力のログを監視します。

2017-01-10 22:36:38.254  INFO 
  [Baeldung Sleuth Tutorial,4e30f7340b3fb631,4e30f7340b3fb631,false] 12516 
  --- [nio-8080-exec-1] c.b.spring.session.SleuthController : Hello Sleuth

括弧の間の最初の部分を除いて、これは通常のログのように見えます。 これは、 SpringSleuthが追加したコア情報です。 このデータは次の形式に従います。

[アプリケーション名、traceId、spanId、エクスポート]

  • アプリケーション名–これは、プロパティファイルで設定した名前であり、同じアプリケーションの複数のインスタンスからのログを集約するために使用できます。
  • TraceId –これは、単一の要求、ジョブ、またはアクションに割り当てられるIDです。 一意のユーザーが開始した各Webリクエストのようなものには、独自のtraceIdがあります。
  • SpanId –作業単位を追跡します。 複数のステップで構成されるリクエストについて考えてみてください。 各ステップは、独自の spanId を持ち、個別に追跡できます。 デフォルトでは、すべてのアプリケーションフローは同じTraceIdとSpanIdで開始されます。
  • Export –このプロパティは、このログがZipkinなどのアグリゲーターにエクスポートされたかどうかを示すブール値です。 Zipkin はこの記事の範囲を超えていますが、Sleuthによって作成されたログの分析において重要な役割を果たします。

ここまでで、このライブラリの威力についてある程度理解しているはずです。 このライブラリがロギングにどれほど統合されているかをさらに示すために、別の例を見てみましょう。

3.2. サービスアクセスを備えたシンプルなWebリクエスト

単一のメソッドでサービスを作成することから始めましょう:

@Service
public class SleuthService {

    public void doSomeWorkSameSpan() {
        Thread.sleep(1000L);
        logger.info("Doing some work");
    }
}

次に、サービスをコントローラーに注入し、それにアクセスするリクエストマッピングメソッドを追加しましょう。

@Autowired
private SleuthService sleuthService;
    
    @GetMapping("/same-span")
    public String helloSleuthSameSpan() throws InterruptedException {
        logger.info("Same Span");
        sleuthService.doSomeWorkSameSpan();
        return "success";
}

最後に、アプリケーションを再起動して、「http:// localhost:8080/same-span」に移動します。 次のようなログ出力に注意してください。

2017-01-10 22:51:47.664  INFO 
  [Baeldung Sleuth Tutorial,b77a5ea79036d5b9,b77a5ea79036d5b9,false] 12516 
  --- [nio-8080-exec-3] c.b.spring.session.SleuthController      : Same Span
2017-01-10 22:51:48.664  INFO 
  [Baeldung Sleuth Tutorial,b77a5ea79036d5b9,b77a5ea79036d5b9,false] 12516 
  --- [nio-8080-exec-3] c.baeldung.spring.session.SleuthService  : Doing some work

メッセージが2つの異なるクラスから発信されている場合でも、トレースIDとスパンIDは2つのログ間で同じであることに注意してください。 これにより、リクエストの traceId を検索することで、リクエスト中に各ログを簡単に識別できます。

これはデフォルトの動作であり、1つのリクエストが単一のtraceIdspanIdを取得します。 ただし、適切と思われる場合は、手動でスパンを追加できます。 この機能を使用する例を見てみましょう。

3.3. 手動でスパンを追加する

まず、新しいコントローラーを追加しましょう。

@GetMapping("/new-span")
public String helloSleuthNewSpan() {
    logger.info("New Span");
    sleuthService.doSomeWorkNewSpan();
    return "success";
}

それでは、サービス内に新しいメソッドを追加しましょう。

@Autowired
private Tracer tracer;
// ...
public void doSomeWorkNewSpan() throws InterruptedException {
    logger.info("I'm in the original span");

    Span newSpan = tracer.nextSpan().name("newSpan").start();
    try (SpanInScope ws = tracer.withSpanInScope(newSpan.start())) {
        Thread.sleep(1000L);
        logger.info("I'm in the new span doing some cool work that needs its own span");
    } finally {
        newSpan.finish();
    }

    logger.info("I'm in the original span");
}

新しいオブジェクトTracerも追加したことに注意してください。 tracer インスタンスは、起動時に Spring Sleuth によって作成され、依存性注入によってクラスで使用できるようになります。

トレースは手動で開始および停止する必要があります。 これを実現するために、手動で作成された span で実行されるコードは、 try-finally ブロック内に配置され、操作の成功に関係なくspanが閉じられるようにします。 また、新しいスパンをスコープに配置する必要があることに注意してください。

アプリケーションを再起動し、「http:// localhost:8080/new-span」に移動します。 次のようなログ出力に注意してください。

2017-01-11 21:07:54.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,9cdebbffe8bbbade,false] 12516 
  --- [nio-8080-exec-6] c.b.spring.session.SleuthController      : New Span
2017-01-11 21:07:54.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,9cdebbffe8bbbade,false] 12516 
  --- [nio-8080-exec-6] c.baeldung.spring.session.SleuthService  : 
  I'm in the original span
2017-01-11 21:07:55.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,1e706f252a0ee9c2,false] 12516 
  --- [nio-8080-exec-6] c.baeldung.spring.session.SleuthService  : 
  I'm in the new span doing some cool work that needs its own span
2017-01-11 21:07:55.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,9cdebbffe8bbbade,false] 12516 
  --- [nio-8080-exec-6] c.baeldung.spring.session.SleuthService  : 
  I'm in the original span

3番目のログはtraceIdを他のログと共有していることがわかりますが、一意のspanIdがあります。 これを使用して、よりきめ細かいトレースを求める1つのリクエストでさまざまなセクションを見つけることができます。

それでは、Sleuthのスレッドのサポートを見てみましょう。

3.4. スパニングランナブル

Sleuth のスレッド機能を示すために、最初に構成クラスを追加してスレッドプールを設定しましょう。

@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の使用に注意することが重要です。 このクラスはSleuthライブラリに由来し、 traceId を新しいスレッドに伝播し、その過程で新しいspanIdを作成する特別な種類のエグゼキュータです。

次に、このエグゼキュータをコントローラに接続して、新しいリクエストマッピングメソッドで使用しましょう。

@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";
}

runnableを配置したら、アプリケーションを再起動して、「http:// localhost:8080/new-thread」に移動します。 次のようなログ出力に注意してください。

2017-01-11 21:18:15.949  
  INFO [Baeldung Sleuth Tutorial,96076a78343c364d,96076a78343c364d,false] 12516 
  --- [nio-8080-exec-9] c.b.spring.session.SleuthController      : New Thread
2017-01-11 21:18:15.950  
  INFO [Baeldung Sleuth Tutorial,96076a78343c364d,96076a78343c364d,false] 12516 
  --- [nio-8080-exec-9] c.b.spring.session.SleuthController      : 
  I'm done - with the original span
2017-01-11 21:18:16.953  
  INFO [Baeldung Sleuth Tutorial,96076a78343c364d,e3b6a68013ddfeea,false] 12516 
  --- [lTaskExecutor-1] c.b.spring.session.SleuthController      : 
  I'm inside the new thread - with a new span

前の例と同じように、すべてのログが同じtraceIdを共有していることがわかります。 ただし、ランナブルからのログには、そのスレッドで実行された作業を追跡する一意のスパンがあります。 これはLazyTraceExecutorが原因で発生することを忘れないでください。通常のエグゼキュータを使用する場合、新しいスレッドで使用されるのと同じspanIdが引き続き表示されます。

次に、@Asyncメソッドに対するSleuthのサポートを調べてみましょう。

3.5. @Asyncサポート

非同期サポートを追加するには、最初に ThreadConfig クラスを変更して、この機能を有効にします。

@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);
    }
}

AsyncConfigurerSupport を拡張して非同期エグゼキューターを指定し、LazyTraceExecutorを使用してtraceIdとspanIdが正しく伝播されるようにすることに注意してください。 また、クラスの先頭に@EnableAsyncを追加しました。

次に、非同期メソッドをサービスに追加しましょう。

@Async
public void asyncMethod() {
    logger.info("Start Async Method");
    Thread.sleep(1000L);
    logger.info("End Async Method");
}

次に、コントローラーからこのメソッドを呼び出します。

@GetMapping("/async")
public String helloSleuthAsync() {
    logger.info("Before Async Method Call");
    sleuthService.asyncMethod();
    logger.info("After Async Method Call");
    
    return "success";
}

最後に、サービスを再起動して、「http:// localhost:8080/async」に移動します。 次のようなログ出力に注意してください。

2017-01-11 21:30:40.621  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,c187f81915377fff,false] 10072 
  --- [nio-8080-exec-2] c.b.spring.session.SleuthController      : 
  Before Async Method Call
2017-01-11 21:30:40.622  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,c187f81915377fff,false] 10072 
  --- [nio-8080-exec-2] c.b.spring.session.SleuthController      : 
  After Async Method Call
2017-01-11 21:30:40.622  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,8a9f3f097dca6a9e,false] 10072 
  --- [lTaskExecutor-1] c.baeldung.spring.session.SleuthService  : 
  Start Async Method
2017-01-11 21:30:41.622  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,8a9f3f097dca6a9e,false] 10072 
  --- [lTaskExecutor-1] c.baeldung.spring.session.SleuthService  : 
  End Async Method

ここでは、実行可能な例と同様に、SleuthtraceIdを非同期メソッドに伝播し、一意のspanIdを追加していることがわかります。

次に、スケジュールされたタスクのspringサポートを使用した例を見ていきましょう。

3.6. @Scheduledサポート

最後に、Sleuth@Scheduledメソッドとどのように連携するかを見てみましょう。 これを行うには、ThreadConfigクラスを更新してスケジューリングを有効にします。

@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 インターフェースを実装し、そのconfigureTasksメソッドをオーバーライドしたことに注意してください。 また、クラスのトップに@EnableSchedulingを追加しました。

次に、スケジュールされたタスクのサービスを追加しましょう。

@Service
public class SchedulingService {

    private Logger logger = LoggerFactory.getLogger(this.getClass());
 
    @Autowired
    private SleuthService sleuthService;

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

このクラスでは、30秒の固定遅延で単一のスケジュールされたタスクを作成しました。

アプリケーションを再起動して、タスクが実行されるのを待ちましょう。 次のような出力については、コンソールを監視してください。

2017-01-11 21:30:58.866  
  INFO [Baeldung Sleuth Tutorial,3605f5deaea28df2,3605f5deaea28df2,false] 10072 
  --- [pool-1-thread-1] c.b.spring.session.SchedulingService     : 
  Start some work from the scheduled task
2017-01-11 21:30:58.866  
  INFO [Baeldung Sleuth Tutorial,3605f5deaea28df2,3605f5deaea28df2,false] 10072 
  --- [pool-1-thread-1] c.b.spring.session.SchedulingService     : 
  End work from scheduled task

ここで、Sleuthがタスクの新しいトレースIDとスパンIDを作成したことがわかります。 タスクの各インスタンスは、デフォルトで独自のトレースとスパンを取得します。

4. 結論

結論として、 SpringSleuthを単一のWebアプリケーション内のさまざまな状況でどのように使用できるかを見てきました。 このテクノロジーを使用すると、リクエストが複数のスレッドにまたがっている場合でも、単一のリクエストからのログを簡単に関連付けることができます。

これで、 Spring Cloud Sleuth が、マルチスレッド環境をデバッグするときに健全性を維持するのにどのように役立つかがわかります。 traceIdの各操作とspanIdの各ステップを識別することで、ログ内の複雑なジョブの分析を実際に分析し始めることができます。

クラウドにアクセスしなくても、 Spring Sleuth は、ほとんどすべてのプロジェクトで重大な依存関係になっている可能性があります。 統合はシームレスであり、は大幅な付加価値です。

ここから、Sleuthの他の機能を調査することができます。 RestTemplate を使用した分散システム、RabbitMQおよびRedisで使用されるメッセージングプロトコル間、およびZuulなどのゲートウェイを介したトレースをサポートできます。

いつものように、ソースコードはGithubにあります。