1. Homepage
  2. Mule Runtime (4.9)
  3. 概要
  4. Mule イベント

  5. Correlation ID (相関 ID)

Correlation ID (相関 ID)

Mule で新しいイベントが作成されると、イベントがフローの次のプロセッサーに送信される前に​相関 ID​ と呼ばれる一意の識別子文字列が生成されます。この ID を使用すると、異なるログエントリを特定の実行と相関することができます。

相関 ID を使用して、問題や未処理のエラーの原因となったイベントのすべての履歴を把握することができます (すべてのエラーに、エラーをトリガーしたイベントの相関 ID が含まれます)。また、相関 ID を知ることで、ヒープダンプのメモリ分析を用意に行うことができます。

相関 ID を取得するため、Mule ではまずソースメッセージ (X-CORRELATION-ID ヘッダーを持つ JMS メッセージや HTTP リスナー) に相関 ID があるかどうかが確認されます。ソースで相関 ID が設定されていない場合、Mule で相関 ID ジェネレーターを使用して相関 ID が生成されます。

相関 ID ジェネレーターの変更

相関 ID ジェネレーターに変更を加えることはお勧めしませんが、次のような場合、イベントの相関 ID を書式設定することが必要になることがあります。

  • 会社に相関 ID に関する独自の標準または形式がある。

  • 外部システムの相関 ID の長さが Mule の相関 ID とは異なるため、それらの互換性がなく、トレースできない。

CloudHub 2.0 では、相関 ID ジェネレーターを有効にしていても、非公開スペースで設定された correlation-id が相関 ID ジェネレーターを上書きします。

Mule での相関 ID の生成方法を変更する手順は、次のとおりです。

  1. <configuration>​ コンポーネントをアプリケーション XML に追加します。

  2. correlationIdGeneratorExpression​ 属性を設定し、相関 ID を生成する式を指定します。

    <configuration correlationIdGeneratorExpression="#[<custom_generator_expression>]"/>
使用しているアルゴリズムでは 2 つの異なるイベントに対して同じ相関 ID を生成できないことを確認してください。

相関 ID ジェネレーターの設定例

次の例では、Mule は Java ​uuid()​ メソッドをコールし、ダッシュ (​-​) をドット (​.​) に置き換えることで、相関 ID を生成します。

<configuration correlationIdGeneratorExpression="#[uuid() replace /-/ with('.')]"/>

<http:listener-config name="HTTP_Listener_config">
  <http:listener-connection host="0.0.0.0" port="8081" />
</http:listener-config>
<flow name="example">
  <http:listener config-ref="HTTP_Listener_config" path="/test"/>
  <set-payload value="some"/>
  <logger level="WARN" message="#[payload]"/>
</flow>

フローの実行後、ロガーに次のように表示されます。

WARN  2021-03-30 16:46:11,269 [[MuleRuntime].uber.06: [test-project-app].example.CPU_LITE @6d3b5ad] [processor: example/processors/1; event: b5a95a63.f190.4c91.880a.5b54512fa6b1] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some

この場合、値 ​b5a95a63.f190.4c91.880a.5b54512fa6b1​ が相関 ID です。

フロー実行中の相関 ID の変更

次のような場合は、特定のスコープまたは一連の操作でイベントの相関 ID を変更することが必要になることがあります。

  • foreach​ スコープ内でデータベースクエリの結果を処理しており、イベントを、処理中のレジスターと相関する必要がある。

  • JMS メッセージキューをコンシュームしており、トレーサビリティの目的で JMS 相関 ID を使用して続行する必要がある。

これらのシナリオでは、Mule Tracing Module をインストールすることで、​with-correlation-id​ スコープを使用して、そのスコープの実行中に相関 ID を変更することができます。

Mule Tracing Module のインストール

アプリケーションに Mule Tracing Module をインストールする手順は、次のとおりです。

  1. Anypoint Studio で Mule プロジェクトを開きます。

  2. [Mule Palette (Mule パレット)] に移動します。

  3. [Search in Exchange (Exchange で検索)]​ を選択して、Mule Tracing Module を検索します。

  4. モジュールを選択し、​[Add (追加)]​ をクリックします。

  5. [Finish (完了)]​ をクリックします。

設定例

次の Mule アプリケーションを考えてみます。

相関 ID スコープ設定が表示されているフロー

アプリケーション XML 設定:

<http:listener-config name="HTTP_Listener_config">
  <http:listener-connection host="0.0.0.0" port="8081" />
</http:listener-config>
<flow name="example">
  <http:listener config-ref="HTTP_Listener_config" path="/test"/>
  <set-payload value="some"/>
  <logger level="WARN" message="#[payload]"/>
  <tracing:with-correlation-id correlationId="#[correlationId ++ '-EXAMPLE']">
    <logger level="WARN" message="#[payload]"/>
  </tracing:with-correlation-id>
  <logger level="WARN" message="#[payload]"/>
</flow>

この場合、アプリケーションでフローを実行すると、出力ログは次のようになります。

WARN  2021-03-30 16:46:11,269 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] [processor: example/processors/1; event: bad0e5b0-9191-11eb-a0b3-36548d51aeee] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some
WARN  2021-03-30 16:46:11,271 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] [processor: example/processors/2/processors/0; event: bad0e5b0-9191-11eb-a0b3-36548d51aeee-EXAMPLE] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some
WARN  2021-03-30 16:46:11,274 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] [processor: example/processors/3; event: bad0e5b0-9191-11eb-a0b3-36548d51aeee] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some

DEBUG ログレベルを使用した追加の相関 ID ログの表示

相関 ID に関連する追加のログを表示する必要がある場合は、次のコードをアプリケーション XML に追加して、ログレベルを ​DEBUG​ に設定します。

<AsyncLogger name="org.mule.runtime.module.extension.internal.runtime.operation" level="DEBUG"/>

次のように、更新されたログが表示されます。

WARN  2021-03-30 16:58:29,545 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] [processor: example/processors/1; event: bad0e5b0-9191-11eb-a0b3-36548d51aeee] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some
DEBUG 2021-03-30 16:58:29,548 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] org.mule.runtime.module.extension.internal.runtime.operation.ImmutableProcessorChildContextChainExecutor: Changing event correlationId from '4c355b30-9192-11eb-b79f-36548d51aeee' to '4c355b30-9192-11eb-b79f-36548d51aeee-EXAMPLE' in location example/processors/2
WARN  2021-03-30 16:58:29,555 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] [processor: example/processors/2/processors/0; event: bad0e5b0-9191-11eb-a0b3-36548d51aeee-EXAMPLE] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some
DEBUG 2021-03-30 16:58:29,566 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] org.mule.runtime.module.extension.internal.runtime.operation.ImmutableProcessorChildContextChainExecutor: Event with correlationId '4c355b30-9192-11eb-b79f-36548d51aeee-EXAMPLE' going back to '4c355b30-9192-11eb-b79f-36548d51aeee' (successful execution) in location example/processors/2
WARN  2021-03-30 16:58:29,568 [[MuleRuntime].uber.05: [test-project-app].example.CPU_LITE @6d3b5ad] [processor: example/processors/3; event: bad0e5b0-9191-11eb-a0b3-36548d51aeee] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some

エラー処理

エラーが発生した場合に、エラーハンドラーで、エラーハンドラーが含まれるフローまたは Try スコープに対応する相関 ID が記録されます。次に例を示します。

<flow name="example">
  <tracing:with-correlation-id correlationId="#[correlationId ++ '-EXAMPLE']">
    <raise-error type="APP:SOME"/>
  </tracing:with-correlation-id>
  <error-handler>
    <on-error-continue>
      <logger message="#[correlationId]"/>
    </on-error-continue>
  </error-handler>
</flow>

このシナリオでは、実行の開始時に設定された相関 ID が Mule によって記録されます。エラーにより相関 ID スコープの実行が停止するため、新しい相関 ID (​#[correlationId ++ '-EXAMPLE']​) が設定されることはありません。

ただし、次の例を考えてみます。

<flow name="example">
  <tracing:with-correlation-id correlationId="#[correlationId ++ '-EXAMPLE']">
    <try>
      <raise-error type="APP:SOME"/>
      <error-handler>
        <on-error-continue>
          <logger message="#[correlationId]"/>
        </on-error-continue>
      </error-handler>
    </try>
  </tracing:with-correlation-id>
</flow>

このシナリオでは、エラーハンドラーは相関 ID スコープ内で実行されるため、フローの実行後に記録された相関 ID は相関 ID スコープ内で設定された相関 ID (​#[correlationId ++ '-EXAMPLE']​) になります。

ログ内で相関 ID を識別する例

次のフローを考えてみます。

<http:listener-config name="HTTP_Listener_config">
  <http:listener-connection host="0.0.0.0" port="8081" />
</http:listener-config>
<flow name="example">
  <http:listener config-ref="HTTP_Listener_config" path="/test"/>
  <set-payload value="some"/>
  <logger level="WARN" message="#[payload]"/>
</flow>

要求を受信した後、フローで次のログが生成されます。

WARN  2021-03-30 14:19:52,862 [[MuleRuntime].uber.04: [test-project-app].example.CPU_LITE @7a3620f2] [processor: example/processors/1; event: 23d22940-917c-11eb-9209-3c22fb13cde7] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some

この場合、値 ​23d22940-917c-11eb-9209-3c22fb13cde7​ が相関 ID です。この ID は対応するイベントの一意の ID です。そのため、この相関 ID を含む他のログは同じイベントを参照しています。

異なる操作から同じ相関 ID を記録する例

次のフローを考えてみます。これは前の例のフローと同じですが、​raise-error​ コンポーネントが含まれます。

<http:listener-config name="HTTP_Listener_config">
  <http:listener-connection host="0.0.0.0" port="8081" />
</http:listener-config>
<flow name="example">
  <http:listener config-ref="HTTP_Listener_config" path="/test"/>
  <set-payload value="some"/>
  <logger level="WARN" message="#[payload]"/>
  <raise-error type="APP:SOME"/>
</flow>

このフローの実行後に、フローで次のログが生成されます。

WARN  2021-03-30 14:27:36,045 [[MuleRuntime].uber.08: [test-project-app].example.CPU_LITE @19afa17] [processor: example/processors/1; event: 37f0f591-917d-11eb-9209-3c22fb13cde7] org.mule.runtime.core.internal.processor.LoggerMessageProcessor: some
ERROR 2021-03-30 14:27:36,052 [[MuleRuntime].uber.08: [test-project-app].example.CPU_LITE @19afa17] [processor: example/processors/2; event: 37f0f591-917d-11eb-9209-3c22fb13cde7] org.mule.runtime.core.internal.exception.OnErrorPropagateHandler:
********************************************************************************
Message               : An error occurred.
Element               : example/processors/2 @ test-project-app:test-project-app.xml:16
Element DSL           : <raise-error type="APP:SOME"></raise-error>
Error type            : APP:SOME
FlowStack             : at example(example/processors/2 @ test-project-app:test-project-app.xml:16)

  (set debug level logging or '-Dmule.verbose.exceptions=true' for everything)
********************************************************************************

Logger および Raise Error コンポーネントが実行されると、両方のコンポーネントで相関 ID ​37f0f591-917d-11eb-9209-3c22fb13cde7​ が記録されます。この相関 ID は、前の例で記録された相関 ID とは異なります。

データベースクエリの相関 ID を設定する例

次の例は、データベースクエリの結果を処理している間に相関 ID を変更できるシナリオを示しています。

Select、For Each、Logger などのコンポーネントが含まれる、相関 ID データベースクエリが表示されているフロー

アプリケーション XML 設定:

<flow name="correlation-id-flow">
  <db:select config-ref="Database_Config">
    <db:sql ><![CDATA[SELECT orderId, customerId, total from Orders  ]]></db:sql>
  </db:select>
  <foreach >
    <tracing:with-correlation-id correlationId="#[payload.orderId]">
      <logger level="INFO" message="#[correlationId]"/>
      <http:request method="GET" url="http://a-service.com" sendCorrelationId="ALWAYS"/>
    </tracing:with-correlation-id>
  </foreach>
</flow>

この場合、データベースから取得した各レコードは ​foreach​ スコープ内で処理され、各反復処理の相関 ID はそのレコードの ​orderId​ に対応します。このシナリオでは、HTTP 要求操作中に問題が発生した場合、相関 ID を使用して、エラーの原因となったレコードを追跡することができます。

関連情報