Gerando mensagens de log

Vamos dar uma olhada melhor em como gerar mensagens de log em C++.

Sumário

  1. Gerando mensagens de log simples
  2. Gerando mensagens de log de tempo único
  3. Gerando mensagens de log de tempo ajustável

Gerando mensagens de log simples

Existem 5 macros básicas de C++ para gerar mensagens de log, um para cada nível de severidade:

ROS_DEBUG_STREAM(message);
ROS_INFO_STREAM(message);
ROS_WARN_STREAM(message);
ROS_ERROR_STREAM(message);
ROS_FATAL_STREAM(message);

O argumento message de cada um desses macros pode lidar exatamente com os tipos de expressões que funcionam com um ostream de C++, como std::cout. Isso inclui usar o operador de inserção («) em tipos primitivos de dado como int ou double, em tipos compostos para os quais esse operador devidamente se submete a overload, e em manipuladores regulares de stream como std::fixed, std::setprecision, ou std::boolalpha.

⚠️ Manipuladores de stream são efetivos apenas na mensagem de log na qual eles aparecem. Quaisquer manipuladores que quiserem usar precisam ser reinseridos toda vez.

⏩ Aqui está o porquê dessa limitação em manipuladores de stream existir: Como seus nomes em caixa alta sugerem, as construções ROS_..._STREAM são macros. Cada uma expande para um bloco curto de código que cria uma std::stringstream e insere os argumentos que você proveu nessa stream. O código expandido, então, envia os conteúdos inteiramente formatados dessa std::stringstream para um sistema de registro interno, nomeado log4cxx. Porque a std::stringstream é destruída quando esse processo acaba, seu estado interno, incluindo qualquer configuração de formatação estabelecida por manipuladores de stream, é perdido.

⏩ Se você preferir uma interface com estilo printf em vez de streams com estilo C++, existem também macros cujos nomes omitem o sufixo “_STREAM”. Por exemplo, o macro

ROS_INFO(format, ...);

gera mensagens de log nível INFO. Esses macros funcionam exatamente como você poderia esperar, pelo menos se você esta familiarizado com printf. Com um exemplo concreto, a linha de saída em Lista 3.4 é ligeiramente equivalente a:

ROS_INFO("position=(%0.2f,%0.2f) direction=%0.2f",
  msg.x, msg.y, msg.theta);

Também existem versões de estilo printf das famílias de macros de tempo único (..._ONCE) e de tempo ajustável (... _THROTTLE) introduzidas abaixo, mais uma vez com nomes que omitem a parte _STREAM.

Note que não há necessidade de usar std::endl nem nenhum encerrador de linha, porque o sistema de registro já é orientado por linhas. Cada ativação para quaisquer um desses macros vai gerar uma única, completa mensagem de log a qual será mostrada em linha única.

Gerando mensagens de log de tempo único

Às vezes, mensagens de log que são geradas dentro de laços ou em funções muito usadas são importantes para o usuário, porém também são irritantemente repetitivas. Uma forma natural de lidar com essas situações seria usar uma variável estática para garantir que a mensagem seja gerada somente uma vez, a primeira vez que é acessada. Lista 4.3 mostra um fragmento de C++ que concretizaria isso.

Lista 4.3

Um fragmento em C++ que desativa uma mensagem de log depois de sua primeira execução. Os macros ROS_... _STREAM_ONCE expandem para blocos de código muito semelhantes. 
// Não faça isso diretamente. Use ROS_..._STREAM_ONCE em vez disso.
{
  static bool first_time = true;
  if(first_time) {
    ROS_INFO_STREAM("Here's␣some␣important␣information"
      << "␣that␣will␣only␣appear␣once.");
    first_time = false;
  }
}

Para evitar repetir esse bloco de código incômodo — envolver ele em uma função não iria funcionar, porque essa técnica demanda uma variável estática distinta para cada declaração — ROS provê macros ágeis que geram precisamente estes tipos de mensagens de log de tempo único.

ROS_DEBUG_STREAM_ONCE(message);
ROS_INFO_STREAM_ONCE(message);
ROS_WARN_STREAM_ONCE(message);
ROS_ERROR_STREAM_ONCE(message);
ROS_FATAL_STREAM_ONCE(message);

A primeira vez que esses macros são identificados durante a execução de um programa, eles geram as mesmas mensagens de log que suas versões correspondentes de tempo não-único. Após essa primeira execução, essas declarações não têm efeito. Lista 4.4 mostra um exemplo mínimo, no qual cada macro de registro gera uma mensagem, na primeira iteração do laço, e são ignorados em todas as futuras iterações.

Lista 4.4

Um programa em C++ chamado once.cpp que gera somente cinco mensagens de log. 
// Esse programa gera somente uma mensagem de log em cada
// nível de severidade.
#include <ros/ros.h>

int main(int argc, char∗∗argv) {
  ros::init(argc, argv, "log_once");
  ros::NodeHandle nh;

  while(ros::ok()) {
   ROS_DEBUG_STREAM_ONCE("This␣appears␣only␣once.");
   ROS_INFO_STREAM_ONCE("This␣appears␣only␣once.");
   ROS_WARN_STREAM_ONCE("This␣appears␣only␣once.");
   ROS_ERROR_STREAM_ONCE("This␣appears␣only␣once.");
   ROS_FATAL_STREAM_ONCE("This␣appears␣only␣once.");
  }
}

Gerando mensagens de log de tempo ajustável

De forma similar, existem macros para ajustar a taxa com a qual uma determinada mensagem de log aparece.

ROS_DEBUG_STREAM_THROTTLE(interval, message);
ROS_INFO_STREAM_THROTTLE(interval, message);
ROS_WARN_STREAM_THROTTLE(interval, message);
ROS_ERROR_STREAM_THROTTLE(interval, message);
ROS_FATAL_STREAM_THROTTLE(interval, message);

O parâmetro interval é uma dupla que especifica a quantidade mínima de tempo, medida em segundos, que precisa passar entre instâncias sucessivas de uma determinada mensagem de log.

Cada instância de qualquer macro ROS_. . . _STREAM_THROTTLEgerará sua mensagem de log pela primeira vez que é executada. execuções subsequentes serão ignoradas, até que uma quantidade de tempo especificada tenha passado. Os tempos limite são cronometrados separadamente (usando uma variável estática local que armazena o tempo de “last hit”) para cada instância de quaisquer desses macros. Lista 4.5 mostra um programa que usa esses macros para se obter comportamento muito parecido com o programa de contagem de Lista 4.1.

Lista 4.5

Um programa em C++ chamado throttle.cpp que mostra mensagens de log ajustáveis. 
// Esse programa gera mensagens de log em níveis de severidade
// variados, ajustados a velocidades máximas variadas.
#include <ros/ros.h>

int main(int argc, char∗∗argv) {
   ros::init(argc, argv, "log_throttled");
   ros::NodeHandle nh;

   while(ros::ok()) {
    ROS_DEBUG_STREAM_THROTTLE(0.1,
      "This␣appears␣every␣0.1␣seconds.");
    ROS_INFO_STREAM_THROTTLE(0.3,
      "This␣appears␣every␣0.3␣seconds.");
    ROS_WARN_STREAM_THROTTLE(0.5,
      "This␣appears␣every␣0.5␣seconds.");
    ROS_ERROR_STREAM_THROTTLE(1.0,
      "This␣appears␣every␣1.0␣seconds.");
    ROS_FATAL_STREAM_THROTTLE(2.0,
      "This␣appears␣every␣2.0␣seconds.");
   }
}

A diferença determinante, além do conteúdo das mensagens, é que o programa em Lista 4.5 consumirá mais tempo de cálculo, ele usa polling, em vez de timed sleeping, para decidir quando é a hora de gerar novas mensagens de log. Esse tipo de polling é, em programas reais, geralmente, uma má ideia.