Logging

A geração de registros e o monitoramento funcionam em conjunto para ajudar a entender e otimizar o desempenho do aplicativo, além de diagnosticar erros e problemas relacionados ao sistema. Após ler este guia, confira o guia de monitoramento para ver algumas práticas recomendadas de monitoramento do aplicativo, incluindo métricas específicas a serem registradas para fins de monitoramento.

Geração de registros de biblioteca de cliente

As bibliotecas de cliente da API Google Ads têm geração de registros integrada. Para detalhes de geração de registros específicos da plataforma, consulte a documentação de geração de registros na sua biblioteca de cliente.

Geração de registros na nuvem

Há muitas ferramentas que você pode usar para capturar registros e métricas de desempenho para seu aplicativo. Por exemplo, é possível usar o Google Cloud Logging para registrar as métricas de desempenho no projeto do Google Cloud. Assim, é possível configurar painéis e alertas no Google Cloud Monitoring para usar as métricas registradas.

O Cloud Logging oferece bibliotecas de cliente para todas as linguagens de biblioteca de cliente da API Google Ads compatíveis, exceto a Perl. Portanto, na maioria dos casos, é possível registrar com o Cloud Logging diretamente da integração da biblioteca de cliente. Para outras linguagens, inclusive Perl, o Cloud Logging também oferece uma API REST.

Existem algumas opções de registro para usar o Cloud Logging, ou outra ferramenta, em uma biblioteca de cliente da API Google Ads. Cada opção tem vantagens e desvantagens de tempo para implementação, complexidade e desempenho. Pense cuidadosamente sobre essas vantagens e desvantagens antes de decidir qual solução implementar.

Opção 1: gravar registros locais na nuvem usando um processo em segundo plano

Os registros da biblioteca de cliente podem ser gravados em um arquivo local na sua máquina modificando a configuração de geração de registros. Quando os registros forem enviados para um arquivo local, será possível configurar um daemon para coletar os registros e enviá-los para a nuvem.

Uma limitação dessa abordagem é que algumas métricas de desempenho não serão capturadas por padrão. Os registros da biblioteca de cliente incluem detalhes dos objetos de solicitação e resposta. Portanto, as métricas de latência não seriam incluídas, a menos que alterações adicionais sejam feitas para registrá-las também.

Opção 2: executar o aplicativo no Compute Engine e instalar o agente de operações

Se o aplicativo estiver em execução no Compute Engine, será possível enviar os registros para o Google Cloud Logging instalando o agente de operações. O agente de operações pode ser configurado para enviar os registros do aplicativo ao Cloud Logging, além das métricas e registros enviados por padrão.

Se o aplicativo já estiver em execução em um ambiente do Google Cloud Platform (GCP) ou se você estiver pensando em transferir o aplicativo para o GCP, essa é uma ótima opção.

Opção 3: implementar a geração de registros no código do aplicativo

A geração de registros diretamente do código do aplicativo pode ser feita de duas maneiras:

  1. Incorporar cálculos de métricas e instruções de registro em todos os locais aplicáveis no código. Essa opção é mais viável para bases de código menores, em que o escopo e os custos de manutenção de tal mudança são mínimos.

  2. Como implementar uma interface de geração de registros. Se a lógica do aplicativo puder ser abstraída para que diferentes partes do aplicativo herdem da mesma classe base, a lógica de geração de registros poderá ser implementada nessa classe base. Geralmente, é melhor usar essa opção do que incorporar log statements em todo o código do aplicativo, já que é mais fácil de manter e escalonar. Para bases de código maiores, a manutenção e a escalonabilidade dessa solução são ainda mais relevantes.

Uma limitação dessa abordagem é que os registros completos de solicitações e respostas não estão disponíveis no código do aplicativo. Os objetos completos de solicitação e resposta podem ser acessados a partir de interceptadores de gRPC. É assim que a geração de registros da biblioteca de cliente integrada recebe registros de solicitação e resposta. Caso ocorra um erro, informações adicionais podem estar disponíveis no objeto de exceção, mas menos detalhes estão disponíveis para respostas bem-sucedidas na lógica do aplicativo. Por exemplo, na maioria dos casos, o ID de uma solicitação bem-sucedida não pode ser acessado a partir dos objetos de resposta da API Google Ads.

Opção 4: implementar um interceptador de geração de registros do gRPC personalizado

O gRPC oferece suporte a interceptadores unário e de streaming, que podem acessar os objetos de solicitação e resposta enquanto passam entre o cliente e o servidor. As bibliotecas de cliente da API Google Ads usam interceptadores gRPC para oferecer suporte integrado à geração de registros. Da mesma forma, é possível implementar um interceptador gRPC personalizado para acessar os objetos de solicitação e resposta, extrair informações para fins de registro e monitoramento e gravar esses dados no local que preferir.

Ao contrário de outras soluções apresentadas aqui, a implementação de um interceptador gRPC personalizado permite flexibilidade para capturar objetos de solicitação e resposta em todas as solicitações, além de implementar outra lógica para capturar detalhes da solicitação. Por exemplo, é possível calcular o tempo decorrido de uma solicitação implementando a lógica de tempo de desempenho no próprio interceptador personalizado e, em seguida, registrar a métrica no Google Cloud Logging para disponibilizá-la para monitoramento de latência no Google Cloud Monitoring.

Interceptador personalizado do Google Cloud Logging em Python

Para demonstrar essa solução, criamos um exemplo de interceptador de geração de registros personalizada em Python. O interceptador personalizado é criado e transmitido para o cliente de serviço. Em seguida, ele acessa os objetos de solicitação e resposta que passam em cada chamada de método de serviço, processa os dados desses objetos e os envia para o Google Cloud Logging.

Além dos dados provenientes dos objetos de solicitação e resposta, o exemplo implementa uma lógica extra para capturar o tempo decorrido da solicitação e alguns outros metadados que são úteis para fins de monitoramento, por exemplo, se a solicitação foi bem-sucedida ou não. Para mais informações sobre como essas informações podem ser úteis, tanto para monitoramento quanto especificamente ao combinar o Google Cloud Logging e o Google Cloud Monitoring, consulte o Guia de monitoramento.

# Copyright 2022 Google LLC
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
#     https://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.
"""A custom gRPC Interceptor that logs requests and responses to Cloud Logging.

The custom interceptor object is passed into the get_service method of the
GoogleAdsClient. It intercepts requests and responses, parses them into a
human readable structure and logs them using the logging service instantiated
within the class (in this case, a Cloud Logging client).
"""

import logging
import time

from google.cloud import logging
from grpc import UnaryUnaryClientInterceptor, UnaryStreamClientInterceptor

from google.ads.googleads.interceptors import LoggingInterceptor, mask_message


class CloudLoggingInterceptor(LoggingInterceptor):
    """An interceptor that logs rpc request and response details to Google Cloud Logging.

    This class inherits logic from the LoggingInterceptor, which simplifies the
    implementation here. Some logic is required here in order to make the
    underlying logic work -- comments make note of this where applicable.
    NOTE: Inheriting from the LoggingInterceptor class could yield unexpected side
    effects. For example, if the LoggingInterceptor class is updated, this class would
    inherit the updated logic, which could affect its functionality. One option to avoid
    this is to inherit from the Interceptor class instead, and selectively copy whatever
    logic is needed from the LoggingInterceptor class."""

    def _init__(self, api_version):
        """Initializer for the CloudLoggingInterceptor.

        Args:
            api_version: a str of the API version of the request.
        """
        super().__init__(logger=None, api_version=api_version)
        # Instantiate the Cloud Logging client.
        logging_client = logging.Client()
        self.logger = logging_client.logger("cloud_logging")

    def log_successful_request(
        self,
        method,
        customer_id,
        metadata_json,
        request_id,
        request,
        trailing_metadata_json,
        response,
    ):
        """Handles logging of a successful request.

        Args:
            method: The method of the request.
            customer_id: The customer ID associated with the request.
            metadata_json: A JSON str of initial_metadata.
            request_id: A unique ID for the request provided in the response.
            request: An instance of a request proto message.
            trailing_metadata_json: A JSON str of trailing_metadata.
            response: A grpc.Call/grpc.Future instance.
        """
        # Retrieve and mask the RPC result from the response future.
        # This method is available from the LoggingInterceptor class.
        # Ensure self._cache is set in order for this to work.
        # The response result could contain up to 10,000 rows of data,
        # so consider truncating this value before logging it, to save
        # on data storage costs and maintain readability.
        result = self.retrieve_and_mask_result(response)

        # elapsed_ms is the approximate elapsed time of the RPC, in milliseconds.
        # There are different ways to define and measure elapsed time, so use
        # whatever approach makes sense for your monitoring purposes.
        # rpc_start and rpc_end are set in the intercept_unary_* methods below.
        elapsed_ms = (self.rpc_end - self.rpc_start) * 1000

        debug_log = {
            "method": method,
            "host": metadata_json,
            "request_id": request_id,
            "request": str(request),
            "headers": trailing_metadata_json,
            "response": str(result),
            "is_fault": False,
            "elapsed_ms": elapsed_ms,
        }
        self.logger.log_struct(debug_log, severity="DEBUG")

        info_log = {
            "customer_id": customer_id,
            "method": method,
            "request_id": request_id,
            "is_fault": False,
            # Available from the Interceptor class.
            "api_version": self._api_version,
        }
        self.logger.log_struct(info_log, severity="INFO")

    def log_failed_request(
        self,
        method,
        customer_id,
        metadata_json,
        request_id,
        request,
        trailing_metadata_json,
        response,
    ):
        """Handles logging of a failed request.

        Args:
            method: The method of the request.
            customer_id: The customer ID associated with the request.
            metadata_json: A JSON str of initial_metadata.
            request_id: A unique ID for the request provided in the response.
            request: An instance of a request proto message.
            trailing_metadata_json: A JSON str of trailing_metadata.
            response: A JSON str of the response message.
        """
        exception = self._get_error_from_response(response)
        exception_str = self._parse_exception_to_str(exception)
        fault_message = self._get_fault_message(exception)

        info_log = {
            "method": method,
            "endpoint": self.endpoint,
            "host": metadata_json,
            "request_id": request_id,
            "request": str(request),
            "headers": trailing_metadata_json,
            "exception": exception_str,
            "is_fault": True,
        }
        self.logger.log_struct(info_log, severity="INFO")

        error_log = {
            "method": method,
            "endpoint": self.endpoint,
            "request_id": request_id,
            "customer_id": customer_id,
            "is_fault": True,
            "fault_message": fault_message,
        }
        self.logger.log_struct(error_log, severity="ERROR")

    def intercept_unary_unary(self, continuation, client_call_details, request):
        """Intercepts and logs API interactions.

        Overrides abstract method defined in grpc.UnaryUnaryClientInterceptor.

        Args:
            continuation: a function to continue the request process.
            client_call_details: a grpc._interceptor._ClientCallDetails
                instance containing request metadata.
            request: a SearchGoogleAdsRequest or SearchGoogleAdsStreamRequest
                message class instance.

        Returns:
            A grpc.Call/grpc.Future instance representing a service response.
        """
        # Set the rpc_end value to current time when RPC completes.
        def update_rpc_end(response_future):
            self.rpc_end = time.perf_counter()

        # Capture precise clock time to later calculate approximate elapsed
        # time of the RPC.
        self.rpc_start = time.perf_counter()

        # The below call is REQUIRED.
        response = continuation(client_call_details, request)

        response.add_done_callback(update_rpc_end)

        self.log_request(client_call_details, request, response)

        # The below return is REQUIRED.
        return response

    def intercept_unary_stream(
        self, continuation, client_call_details, request
    ):
        """Intercepts and logs API interactions for Unary-Stream requests.

        Overrides abstract method defined in grpc.UnaryStreamClientInterceptor.

        Args:
            continuation: a function to continue the request process.
            client_call_details: a grpc._interceptor._ClientCallDetails
                instance containing request metadata.
            request: a SearchGoogleAdsRequest or SearchGoogleAdsStreamRequest
                message class instance.

        Returns:
            A grpc.Call/grpc.Future instance representing a service response.
        """

        def on_rpc_complete(response_future):
            self.rpc_end = time.perf_counter()
            self.log_request(client_call_details, request, response_future)

        # Capture precise clock time to later calculate approximate elapsed
        # time of the RPC.
        self.rpc_start = time.perf_counter()

        # The below call is REQUIRED.
        response = continuation(client_call_details, request)

        # Set self._cache to the cache on the response wrapper in order to
        # access the streaming logs. This is REQUIRED in order to log streaming
        # requests.
        self._cache = response.get_cache()

        response.add_done_callback(on_rpc_complete)

        # The below return is REQUIRED.
        return response