Instrumentação personalizada com OpenTelemetry custom-instrumentation

Quando a OpenTelemetry está habilitada para o seu ambiente, o AEM as a Cloud Service rastreia todas as solicitações e exporta métricas JVM, HTTP e AEM automaticamente. Essa telemetria descreve o AEM. Ela mostra que uma página levou 900 milissegundos para ser renderizada e quais componentes foram renderizados. Ele não pode mostrar o que seu próprio código estava fazendo, como para qual item de lista uma consulta de repositório era e se encontrou algo ou quais páginas retornam a uma pesquisa cara porque um autor deixou de fora um campo.

Você mesmo pode adicionar esse conhecimento com a API OpenTelemetry. As extensões e os atributos que seu código cria com a telemetria automática: mesmo nome de serviço, mesmo processamento, mesmo provedor de APM. Você não configura um endpoint, uma credencial ou um exportador em seu código.

Se você é novo no OpenTelemetry no AEM as a Cloud Service, comece com o tutorial Observabilidade via OpenTelemetry para saber como ele funciona. Siga Configurar OpenTelemetry para insights sobre aplicativos AEM para habilitá-lo para o seu ambiente.

Os exemplos nesta página instrumentam o site de referência WKND. Cada exemplo descreve o que você deseja alcançar, o código a ser adicionado e o resultado que você pode esperar em seu provedor de APM. O código instrumentado completo, incluindo testes de unidade que declaram nos spans, está na ramificação tutorial/otel-custom-instrumentation do repositório WKND.

Como a instrumentação personalizada funciona how-it-works

Configurar um projeto set-up-project

Etapa 1: adicionar a API OpenTelemetry add-api

Adicione a API OpenTelemetry e as anotações de instrumentação à seção dependencyManagement do pai do projeto pom.xml, com o escopo 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>

Em seguida, adicione ambas as dependências, sem versões, ao pom.xml de cada pacote que as utiliza, como 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>

Use o opentelemetry-api 1.61.0 e o opentelemetry-instrumentation-annotations 2.27.0 ou versões anteriores. Eles correspondem ao agente Java OpenTelemetry que o AEM as a Cloud Service executa e as versões posteriores do agente continuam a oferecer suporte a eles. Os recursos de API adicionados após a versão que o agente aceita não têm efeito.

Etapa 2: incorporar a API ao seu pacote embed-api

O AEM as a Cloud Service não exporta os pacotes da API OpenTelemetry, portanto, cada pacote que usa a API deve conter sua própria cópia. Adicione as instruções a seguir à configuração de ligação do seu pacote. Com o Arquétipo de Projeto do AEM, essa é a configuração bnd-maven-plugin em core/pom.xml. Mantenha todas as entradas que a instrução Import-Package já tenha.

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

Cada pacote que usa a API incorpora sua própria cópia, e o agente conecta cada cópia separadamente.

Etapa 3: criar um rastreador create-tracer

Crie um Tracer para sua base de código e reutilize-o em qualquer lugar. Na WKND, uma pequena classe a mantém:

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() {
    }
}

O nome do escopo aparece em cada span criado por meio desse rastreador, como o escopo de instrumentação (ou nome da biblioteca). Use um nome que identifique o código, como o pacote Java básico do projeto.

Onde as extensões aparecem where-spans-appear

No AEM as a Cloud Service, uma solicitação de página já produz extensões do próprio AEM. As extensões criadas pelo código são adicionadas dentro delas. Por exemplo, este é o caminho para o componente Lista de imagens em um rastro da página da 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

Enquanto um componente é renderizado, a extensão de seu script HTL é a extensão atual. Um Modelo Sling que o script carrega com data-sly-use é executado dentro desse intervalo, de modo que os intervalos que o modelo cria se tornam seus filhos.

Cada intervalo de solicitação é nomeado como GET /* (ou POST /* e assim por diante). Para localizar os rastreamentos de uma página específica, pesquise no atributo url.path do intervalo da solicitação ou adicione seus próprios atributos, conforme mostrado no Exemplo 3.

Exemplos examples

Exemplo 1: Rastrear uma operação cara trace-operation

O que você deseja alcançar trace-operation-goal

O componente Lista de Imagens WKND (wknd/components/image-list) exibe uma lista de páginas, cada uma com sua primeira imagem. Para localizar essa imagem, seu Modelo Sling, ImageListImpl, executa uma consulta QueryBuilder para cada item na lista. As próprias extensões do AEM já mostram essas consultas: na página da WKND Magazine, que lista cinco artigos, o rastreamento contém cinco extensões JCR query no intervalo HTL da Lista de imagens. Eles não mostram para qual item de lista cada consulta era, se encontrou uma imagem ou o tempo gasto processando os resultados. O código original cronometrava a consulta com System.currentTimeMillis() e gravava o resultado em uma entrada de log DEBUG, que não está disponível na produção. Você deseja que cada consulta apareça no rastreamento como uma operação nomeada, com esse contexto.

O código trace-operation-code

Em ImageListImpl.findPageComponentResources(), crie uma extensão em torno da consulta:

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;

O resultado trace-operation-outcome

Na página da Revista WKND, que lista cinco artigos, o rastreamento agora contém cinco ImageList.findPageComponentResources extensões dentro da Lista de Imagens, uma para cada item da lista. Cada um é o pai do span JCR query que o AEM cria para sua 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

Cada uma das extensões tem o escopo de instrumentação com.adobe.aem.guides.wknd e os seguintes atributos:

Agora é possível ver, para cada item de lista, qual página a consulta pesquisou, se encontrou uma imagem (wknd.query.result_count é 0 quando não encontrou) e quanto tempo demorou a pesquisa inteira, incluindo o processamento dos resultados. Na página da WKND Magazine, cada pesquisa leva cerca de 6,5 milissegundos, dos quais a própria consulta do repositório leva cerca de 3,5: metade do tempo entra no processamento dos resultados, que as próprias extensões do AEM não mostram. Como a contagem de consultas cresce com o comprimento da lista, você também pode ver quanto do tempo de renderização do componente as pesquisas levam em conta.

Exemplo 2: Rastrear um método com uma anotação with-span

O que você deseja alcançar with-span-goal

O modelo SocialImageImpl da WKND é executado em cada página para preencher a meta tag og:image. Se um autor não tiver definido uma imagem em destaque, o modelo percorrerá a árvore de conteúdo da página para encontrar a primeira imagem, visitando até 500 recursos. Você quer saber com que frequência essa caminhada é realizada e quanto da árvore ele visita, sem reestruturar o método.

O código with-span-code

Anotar o método com @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
}

O resultado with-span-outcome

Um span SocialImage.resolveFromFirstImageOnPage aparece somente nos rastreamentos de páginas que não têm imagem em destaque:

Procure por esse nome de span para listar as páginas que precisam de uma imagem em destaque. Se wknd.social_image.walk_truncated for true, a caminhada parou em 500 recursos e a página pode não ter nenhuma imagem social.

As extensões criadas por @WithSpan carregam o escopo de instrumentação do agente (io.opentelemetry.opentelemetry-instrumentation-annotations-1.16), não o seu.

Exemplo 3: Adicionar contexto de negócios ao intervalo atual current-span

O que você deseja alcançar current-span-goal

Você deseja filtrar os rastreamentos pelo fato de que seu código sabe, aqui, de onde veio a imagem social da página, sem criar outro intervalo.

O código current-span-code

Em SocialImageImpl, adicione um atributo ao span que já está ativo:

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

O resultado current-span-outcome

A extensão do script customheaderlibs.html da página, onde o WKND carrega esse modelo, carrega wknd.social_image.source com o valor featured_image, first_image_on_page ou none. Procure rastreamentos onde wknd.social_image.source é none para localizar as páginas publicadas sem uma imagem social.

No site WKND, cada página relata first_image_on_page ou none: nenhuma página define uma imagem em destaque, portanto, cada página paga pela caminhada da árvore de conteúdo de Exemplo 2. Configurar uma imagem em destaque nas páginas mais visitadas remove esse trabalho.

Exemplo 4: Registrar um erro record-errors

O que você deseja alcançar record-errors-goal

O modelo ContentAIAvailabilityImpl da WKND verifica se a Pesquisa com IA de conteúdo está configurada ao ler uma configuração OSGi. Se a pesquisa falhar, o modelo tratará a IA de conteúdo como não configurada e registrará um aviso. A página ainda é renderizada e a solicitação é bem-sucedida, portanto, a falha é fácil de perder. Você deseja que a falha apareça nas visualizações de erro do provedor de APM, anexadas à operação que falhou.

O código 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();
    }
}

O resultado record-errors-outcome

O rastreamento contém um ContentAIAvailability.resolveConfigured span com o status Erro e a descrição Content AI configuration lookup failed. O span tem um evento exception:

O span conta como um erro no provedor de APM, portanto, é exibido sempre que o provedor mostra operações com falha. O intervalo da solicitação mantém seu status, pois a solicitação retornou HTTP 200.

Exemplo 5: correlacionar logs com rastreamentos correlate-logs

O que você deseja alcançar correlate-logs-goal

Quando a pesquisa da IA de Conteúdo no Exemplo 4 falhar, você desejará ir do aviso em seus logs para o rastreamento da solicitação que o produziu e voltar.

O código correlate-logs-code

Você não precisa de nenhum código OpenTelemetry. Faça logon com SLF4J como de costume e habilite os logs (logs: true) na sua configuração de OpenTelemetry:

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

O agente adiciona as IDs de rastreamento e span da extensão atual a cada entrada de log. Como ContentAIAvailabilityImpl faz logon enquanto seu span de Exemplo 4 é atual, o aviso é vinculado a esse span.

O resultado correlate-logs-outcome

Seu provedor APM recebe uma entrada de log como a seguinte e pode mostrá-la com seu rastreamento:

Práticas recomendadas best-practices

Testar sua instrumentação test

Resolução de problemas troubleshooting

Artigos relacionados related-articles