OpenTelemetryを使用したカスタム計測 custom-instrumentation

環境でOpenTelemetryが有効になっている場合、AEM as a Cloud Serviceはすべてのリクエストをトレースし、JVM、HTTP、AEMの指標を自動的に書き出します。 このテレメトリはAEMを表しています。 これは、ページのレンダリングに900 ミリ秒かかったこと、およびどのコンポーネントがレンダリングされたかを示しています。 リポジトリクエリのリスト項目や見つかったページ、作成者がフィールドを省略したために高額な検索にフォールバックしたページなど、独自のコードが何であったかを表示することはできません。

OpenTelemetry APIを使用して、その知識を自分で追加することができます。 コードが作成するスパンと属性は、自動テレメトリ（同じサービス名、同じ処理、同じAPM プロバイダー）を使用して移動します。 コードにエンドポイント、資格情報、エクスポーターを設定しないでください。

AEM as a Cloud ServiceでOpenTelemetryを初めて使用する場合は、チュートリアル「OpenTelemetryを使用したオブザーバビリティ ​」から始めて、その仕組みについて説明します。 次に、AEM アプリケーションのインサイトを得るためにOpenTelemetryを設定しお使いの環境で有効にします。

このページの例では、WKND参照サイト ​を計測しています。 それぞれの例では、達成したい目標、追加するコード、APM プロバイダーで期待できる成果について説明します。 スパンでアサートする単体テストを含む、完全なインストルメント化されたコードは、WKND リポジトリのtutorial/otel-custom-instrumentation ブランチにあります。

カスタムインストルメンテーションの仕組み how-it-works

プロジェクトの設定 set-up-project

手順1:OpenTelemetry APIの追加 add-api

プロジェクトの親pom.xmlのdependencyManagement セクションに、OpenTelemetry APIとインストルメンテーション注釈をprovided スコープで追加します。

<properties>
    <opentelemetry.version>1.61.0</opentelemetry.version>
    <opentelemetry-instrumentation.version>2.27.0</opentelemetry-instrumentation.version>
</properties>

<dependencyManagement>
    <dependencies>
        <dependency>
            <groupId>io.opentelemetry</groupId>
            <artifactId>opentelemetry-api</artifactId>
            <version>${opentelemetry.version}</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>io.opentelemetry.instrumentation</groupId>
            <artifactId>opentelemetry-instrumentation-annotations</artifactId>
            <version>${opentelemetry-instrumentation.version}</version>
            <scope>provided</scope>
        </dependency>
    </dependencies>
</dependencyManagement>

次に、バージョンを使用しない両方の依存関係を、それらを使用する各バンドルのpom.xmlに追加します（core/pom.xmlなど）。

<dependency>
    <groupId>io.opentelemetry</groupId>
    <artifactId>opentelemetry-api</artifactId>
</dependency>
<dependency>
    <groupId>io.opentelemetry.instrumentation</groupId>
    <artifactId>opentelemetry-instrumentation-annotations</artifactId>
</dependency>

opentelemetry-api 1.61.0およびopentelemetry-instrumentation-annotations 2.27.0以前のバージョンを使用してください。 これらはAEM as a Cloud Serviceが実行するOpenTelemetry Java エージェントと一致し、以降のバージョンのエージェントは引き続きそれらをサポートします。 エージェントがサポートするバージョンの後に追加されたAPI機能は影響しません。

ステップ 2: APIをバンドルに埋め込む embed-api

AEM as a Cloud ServiceはOpenTelemetry API パッケージを書き出さないので、APIを使用する各バンドルには独自のコピーを含める必要があります。 バンドルのバンド設定に次の手順を追加します。 AEM プロジェクト アーキタイプ ​では、これはcore/pom.xmlのbnd-maven-plugin設定です。 Import-Package命令が既に持っているエントリはすべて保持します。

Import-Package: !io.opentelemetry.*,javax.annotation;version=0.0.0,*
-includepackage: io.opentelemetry.*

APIを使用する各バンドルには独自のコピーが埋め込まれ、エージェントは各コピーを個別に接続します。

手順3：トレーサーの作成 create-tracer

コードベース用に1つのTracerを作成し、どこでも再利用できます。 WKNDでは、小さなクラスが保持しています。

package com.adobe.aem.guides.wknd.core.telemetry;

import io.opentelemetry.api.GlobalOpenTelemetry;
import io.opentelemetry.api.trace.Tracer;

public final class WkndTelemetry {

    /** Instrumentation scope: identifies telemetry produced by WKND code in your APM provider. */
    public static final String SCOPE = "com.adobe.aem.guides.wknd";

    public static final Tracer TRACER = GlobalOpenTelemetry.getTracer(SCOPE);

    private WkndTelemetry() {
    }
}

スコープ名は、このトレーサーを通じて作成したすべてのスパンに、インストルメンテーションスコープ（またはライブラリ名）として表示されます。 プロジェクトのベース Java パッケージなど、コードを識別する名前を使用します。

スパンが表示される場所 where-spans-appear

AEM as a Cloud Serviceでは、ページリクエストは既にAEM自体からスパンを生成しています。 コードが作成するスパンは、その中に追加されます。 例えば、WKND Magazine ページのトレース内の画像リストコンポーネントへのパスを次に示します。

GET /*                                                     the request (AEM)
└─ SlingMainServlet.service                                Sling request processing (AEM)
   └─ AEM component: cq:Page                               (AEM)
      └─ AEM component: wknd/components/page               the page component (AEM)
         └─ HTL: libs.core.wcm.components.page.v3.page.page__002e__html
            └─ ...                                         containers and layout grids (AEM)
               └─ AEM component: wknd/components/image-list
                  └─ HTL: apps.wknd.components.image__002d__list.image__002d__list__002e__html
                     └─ ...                                spans that the Image List's Sling Model creates

コンポーネントのレンダリング中、HTL スクリプトのスパンは現在のスパンになります。 スクリプトがdata-sly-useで読み込まれるSling モデルは、そのスパン内で実行されるので、モデルが作成するスパンはその子になります。

すべてのリクエストスパンにはGET /* （またはPOST /*など）という名前が付けられます。 特定のページのトレースを検索するには、例3に示すように、リクエストスパンのurl.path属性を検索するか、独自の属性を追加します。

例 examples

例1：高価な操作をトレースする trace-operation

達成したいこと trace-operation-goal

WKND画像リストコンポーネント （wknd/components/image-list）には、ページのリストが表示され、それぞれに最初の画像が表示されます。 その画像を見つけるために、そのSling モデル ImageListImplは、リスト内の各項目に対して1つのQueryBuilder クエリを実行します。 AEMの独自のスパンには、既にそれらのクエリが表示されています。5つの記事を一覧表示するWKND Magazine ページでは、画像リストのHTL スパンの下に5つのJCR query スパンが含まれています。 各クエリがどのリスト項目であったか、画像が見つかったか、結果の処理に費やされた時間は表示されません。 元のコードはSystem.currentTimeMillis()でクエリをタイムアウトし、その結果をDEBUG ログエントリに書き込みました。これは実稼動環境では利用できません。 各クエリは、そのコンテキストを持つ名前付き操作としてトレースに表示する必要があります。

コード trace-operation-code

ImageListImpl.findPageComponentResources()で、クエリの周りにスパンを作成します。

import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.StatusCode;
import io.opentelemetry.context.Scope;

// ... build the QueryBuilder parameters, as before

final Span span = WkndTelemetry.TRACER.spanBuilder("ImageList.findPageComponentResources")
        .setAttribute("wknd.query.path", page.getContentResource().getPath())
        .setAttribute("wknd.query.resource_type", slingResourceType)
        .setAttribute("wknd.query.limit", limit)
        .startSpan();

try (Scope ignored = span.makeCurrent()) {
    // ... run the query and collect the resources, as before

    span.setAttribute("wknd.query.result_count", componentResources.size());
} catch (RuntimeException e) {
    span.recordException(e);
    span.setStatus(StatusCode.ERROR, "Image List query failed");
    throw e;
} finally {
    span.end();
}

return componentResources;

成果 trace-operation-outcome

5つの記事を一覧表示するWKND Magazine ページで、トレースに画像リスト内に5つのImageList.findPageComponentResources スパンが含まれるようになりました。各リスト項目に1つずつ表示されます。 各ノードは、AEMがクエリ用に作成するJCR query スパンの親です。

AEM component: wknd/components/image-list
└─ HTL: apps.wknd.components.image__002d__list.image__002d__list__002e__html
   ├─ ImageList.findPageComponentResources        your span
   │  └─ JCR query                                AEM
   ├─ ImageList.findPageComponentResources
   │  └─ JCR query
   └─ ...                                         three more

各スパンには、インストルメンテーション スコープ com.adobe.aem.guides.wkndと次の属性があります。

検索した各リスト項目について、クエリが検索したページ、画像が見つかったかどうか（wknd.query.result_countは見つからなかったとき0）、検索結果の処理を含む検索全体にかかる時間を確認できるようになりました。 WKND Magazine ページでは、各ルックアップに約6.5 ミリ秒かかります。リポジトリクエリ自体は約3.5秒かかります。その半分の時間が結果の処理に費やされ、AEM独自のスパンは表示されません。 クエリ数はリストの長さに合わせて増加するので、ルックアップアカウントでコンポーネントのレンダリング時間がどの程度になるかを確認することもできます。

例2：注釈を使用してメソッドをトレースする with-span

達成したいこと with-span-goal

WKNDのSocialImageImpl モデルは、og:image メタタグを入力するためにすべてのページで実行されます。 制作者が注目画像を設定していない場合、モデルはページのコンテンツツリーを歩いて最初の画像を見つけ、最大500件のリソースを訪問します。 あなたは、その歩きが実行される頻度と、それが訪問する木の量を知りたいと思います。

コード with-span-code

メソッドに@WithSpanの注釈を付けます：

import io.opentelemetry.api.trace.Span;
import io.opentelemetry.instrumentation.annotations.WithSpan;

@WithSpan("SocialImage.resolveFromFirstImageOnPage")
protected boolean resolveFromFirstImageOnPage() {
    Resource contentResource = currentPage.getContentResource();
    if (contentResource == null) {
        return false;
    }

    int[] visitedCount = new int[]{0};
    Resource firstImage = findFirstImage(contentResource, 0, visitedCount);

    // Span.current() is the span that @WithSpan started for this method.
    Span.current().setAttribute("wknd.social_image.nodes_visited", visitedCount[0]);
    Span.current().setAttribute("wknd.social_image.walk_truncated", visitedCount[0] > MAX_NODES_TO_VISIT);

    // ... use firstImage, as before
}

成果 with-span-outcome

SocialImage.resolveFromFirstImageOnPage スパンは、おすすめ画像のないページのトレースにのみ表示されます。

このスパン名を検索して、おすすめ画像が必要なページを一覧表示します。 wknd.social_image.walk_truncatedがtrueの場合、ウォークは500 リソースで停止し、ページにはソーシャル イメージがまったく表示されない可能性があります。

@WithSpanによって作成されたスパンは、あなたのものではなく、エージェントのインストルメンテーション スコープ （io.opentelemetry.opentelemetry-instrumentation-annotations-1.16）を実行します。

例3：現在のスパンにビジネスコンテキストを追加する current-span

達成したいこと current-span-goal

コードが、ページのソーシャルイメージがどこから来たのかを、別のスパンを作成することなく知っているという事実でトレースをフィルタリングしたい場合。

コード current-span-code

SocialImageImplで、既にアクティブなスパンに属性を追加します。

import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.trace.Span;

private static final AttributeKey<String> IMAGE_SOURCE = AttributeKey.stringKey("wknd.social_image.source");

@PostConstruct
protected void init() {
    if (currentPage == null) {
        return;
    }

    final String source;
    if (resolveFromFeaturedImage()) {
        source = "featured_image";
    } else if (resolveFromFirstImageOnPage()) {
        source = "first_image_on_page";
    } else {
        source = "none";
    }

    Span.current().setAttribute(IMAGE_SOURCE, source);
}

成果 current-span-outcome

WKNDがこのモデルを読み込むページのcustomheaderlibs.html スクリプトのスパンには、値featured_image、first_image_on_page、またはnoneを持つwknd.social_image.sourceが含まれます。 wknd.social_image.sourceがnoneのトレースを検索して、ソーシャルイメージなしで公開されているページを見つけます。

WKND サイトでは、すべてのページがfirst_image_on_pageまたはnoneと報告しています。おすすめ画像を設定するページはないので、例2からコンテンツツリーウォークに対して各ページが支払いを行います。 最も訪問されたページに特集画像を設定すると、その作業が削除されます。

例4：エラーを記録する record-errors

達成したいこと record-errors-goal

WKNDのContentAIAvailabilityImpl モデルは、コンテンツ AI 検索がOSGi設定を読み取って設定されているかどうかを確認します。 ルックアップが失敗した場合、モデルはContent AIを設定されていないものとして扱い、警告をログに記録します。 ページは引き続きレンダリングされ、リクエストが成功するので、失敗を見逃しやすくなります。 失敗した操作に添付された、APM プロバイダーのエラービューに失敗を表示する必要があります。

コード record-errors-code

import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.StatusCode;
import io.opentelemetry.context.Scope;

private boolean resolveConfigured() {
    if (configurationAdmin == null) {
        return false;
    }
    final Span span = WkndTelemetry.TRACER.spanBuilder("ContentAIAvailability.resolveConfigured").startSpan();
    // Close the scope in finally, not with try-with-resources: try-with-resources closes it before
    // the catch block runs, and the warning logged there must carry this span's trace and span IDs.
    final Scope scope = span.makeCurrent();
    try {
        Configuration configuration = lookupConfiguration();
        // ... read the API key, as before
        span.setAttribute("wknd.content_ai.configured", isConfigured);
        return isConfigured;
    } catch (IOException e) {
        span.recordException(e);
        span.setStatus(StatusCode.ERROR, "Content AI configuration lookup failed");
        LOGGER.warn("Unable to determine whether Content AI is configured (PID {})", CONTENT_AI_CLIENT_PID, e);
        return false;
    } finally {
        scope.close();
        span.end();
    }
}

成果 record-errors-outcome

トレースには、ステータス エラー​と説明Content AI configuration lookup failedを含むContentAIAvailability.resolveConfigured スパンが含まれています。 スパンにexception イベントがあります：

スパンはAPM プロバイダーのエラーとしてカウントされるので、プロバイダーが失敗した操作を示す場所に表示されます。 リクエストがHTTP 200を返したので、リクエストのスパンはステータスを保持します。

例5: ログとトレースの関連付け correlate-logs

達成したいこと correlate-logs-goal

例4のコンテンツ AI ルックアップが失敗した場合、ログ内の警告から、それを生成したリクエストのトレースに移動して、戻る必要があります。

コード correlate-logs-code

OpenTelemetry コードは必要ありません。 通常どおりSLF4Jでログを記録し、OpenTelemetry設定でログ （logs: true）を有効にします。

LOGGER.warn("Unable to determine whether Content AI is configured (PID {})", CONTENT_AI_CLIENT_PID, e);

エージェントは、現在のスパンのトレース IDとスパン IDを各ログエントリに追加します。 ContentAIAvailabilityImplは、例4からのスパンが現在の状態でログを記録するため、警告はそのスパンにリンクされます。

成果 correlate-logs-outcome

APM プロバイダーは、次のようなログエントリを受け取り、トレースを使用して表示できます。

ベストプラクティス best-practices

インストルメンテーションのテスト test

トラブルシューティング troubleshooting

関連記事 related-articles