O log é uma parte importante de qualquer sistema que precisa de análise em caso de falhas ou de monitoração de seja lá qual for o dado que é exposto lá.
Podemos usar como exemplo os seguintes cenários
- Um sistema de negociação gera um dado incorreto. Como descobrir isso se você não sabe o que gerou a falha ?
- Um sistema de restaurantes deu um erro, mas o restaurante fica num lugar ermo e de difícil acesso para que seja feita uma análise no local.
- Um sistema escreve no log informações de carga e tempo processamento dos dados.
Update: Número de parâmetros !
Com base nisso, podemos pensar em algumas características importantes em uma biblioteca de log, ou até melhor, quais são as características necessárias para uma biblioteca de log e quais são os problemas que me fariam não usar uma nova nos meus projetos ?
- Não pode causar falhas no sistema ou gerar exceções
- Não pode resolver os parâmetros caso o log não seja gerado.
- Precisa ter o número de parâmetros variável
- Não pode pode gastar mais tempo do que o realmente necessário
- Precisa ser adaptável a sistemas de log já existentes
- Precisa ser flexível a ponto de eu ter várias possibilidades de implementações
Como a minha linguagem de maior domínio, e também a que mais costuma estar em sistemas de alta performance é C++, vou manter tudo relacionado a ela somente.
Vamos falar um pouco sobre cada ponto.
Não pode causar falhas no sistema ou gerar exceções
Muitos geradores de logs são baseados em sprintf ou boost::format. Esse é um possível gerador de problemas. Vejamos o exemplo.
log.debug("[%d] Message received: %s") % msg->to_string();
A linha acima tem dois problemas.
- Ela vai gerar uma exceção pois tem dois parametros de formatação, mas só passa um.
- Ela está fazendo a resolução de to_string, mesmo que o log em debug não seja logado, pois o parâmetro é resolvido antes do método ser invocado. É um caso típico de eager evaluation
Uma solução para isso seria ter a chamada da forma abaixo:
log.debug("[", thread_id, "] Message received: ", msg->to_string());
Da forma mostrada agora, nunca será gerada uma exceção de formatação, mas ainda poderia gerar um crash se msg for null. Eu ainda continuo com o problema de resolução do to_string e gasto desnecessário de CPU.
Precisa ter o número de parâmetros variável
Um dos geradores de problemas nos logs é número de parâmetros variáveis. A forma padrão, vinda do C, é a formatação estilo printf
printf("%d - Message received: %s", thread_id, msg->to_string());
O problema disso é o mesmo do boost format. Se a quantidade de parâmetros não coincidir com a formatação, teremos problemas.
Para resolver isso, eu preciso usar variadic templates. Assim os parâmetros serão resolvidos em tempo de compilação, sem problemas de performance ou questões de formatação.
template <typename T>
void _log(StreamPolicy &st, T &t) {
log_formatter<T, StreamPolicy>(st, t);
}
template <typename T, typename ...U>
void _log(StreamPolicy &ss, T &t, U&&... p) {
log_formatter<T, StreamPolicy>(ss, t);
_log(ss, p...);
}
template <typename ...T>
void log(log_level level, T&&... p) {
if( !is_level_enabled(level) )
return;
StreamPolicy ss;
_log(ss, p...);
_log_callback((int)level, ss.str());
}
Aqui estamos recebendo uma quantidade variável de parâmetros em T&&… p e passando para o método _log.
Este agora irá descascar o template fazendo várias chamadas ao log_formatter, até que complete a linha e todos os parâmetros estejam concatenados. Isso garante que tenhamos tudo resolvido em tempo de compilação e não haja custo adicional em runtime.
Não pode resolver os parâmetros caso o log não seja gerado.
Nós podemos tratar o problema da mensagem nula usando uma técnica bem simples. O Lazy evaluation, e ainda de cara resolvemos o problema do parâmetro sendo resolvido desnecessariamente. Nós precisamos somente transformar em lazy evaluation a nossa formatação de mensagem
#define TP std::make_tuple
log.debug("[",thread_id,"] Message received: ", TP(msg,to_string));
Essa tupla será armazenada num parâmetro e resolvida somente depois, caso o nível de log esteja de acordo e o log seja gerado. Dentro do método to_string, eu posso fazer a validação que eu achar necessária.
std::string to_string(const Message *msg) {
if( msg == nullptr ) return "null";
return msg->to_string();
}
Isso pode gerar o mesmo
Não pode pode gastar mais tempo do que o realmente necessário
Aqui já temos um ponto resolvido. A resolução de parâmetros de forma lazy já tira uma parte do problema.
Outra parte se deve ser endereçada a uma policy para que eu tenha no meu sistema a implementação que eu achar melhor de um stream.
template<typename T, typename StreamPolicy>;
struct log_formatter {
log_formatter(StreamPolicy &st, T &t) {
st << t;
}
};
log_formatter<std::string, MyInsanelyFastStream>(stream, date);
//ou
log_formatter<std::string, MyAsyncStream>(stream, date);
Eu consigo dessa forma fazer com que a implementação de stream seja flexível e rápida.
Precisa ser adaptável a sistemas de log já existentes
Aqui temos uma situação comum nas empresas. Eu tenho uma implementação de log que já é usada e eu não posso e nem quero trocar dos módulos já existentes. Os dois logs precisam coexistir e ninguém quer dois arquivos de log diferentes por causa disso.
Uma forma de fazer essa coexistência é o log gerar um callback para que eu use a implementação que eu quiser.
Logger::init(log_level::ALL, [](int level, const std::string &text) {
Level l = to_legacy_level(level);
LegacyLogger::log(l, text);
});
Precisa ser flexível a ponto de eu ter várias possibilidades de implementações
Na minha implementação atual, a forma de callback é obrigatória e ela está feita usando stream (com operador <<). Duas coisas interessantes que poderiam virar policies é o próprio callback ser uma Policy, podendo ser trocado por qualquer outra coisa e o uso de stream ser outra. Fico aberto a sugestões !
A implementação atual do log ainda é um draft e eu preciso fazer testes com ela e comparar com outros geradores. Sugestões e críticas são muito bem vindas.
One thought on “Proposta para um log melhor”