Penna: logging estruturado em JSON para a JVM · hkupty

Olá! Nesse breve artigo gostaria de falar um pouco sobre o meu projeto, penna, discutir os motivos que me levaram a criar o projeto e, quem sabe em breve, abrir também um pouco de como eu fiz ele ser tão eficiente.

Pano de fundo

Eu tenho visto através dos anos um pattern muito recorrente: escrever logs em JSON para o stdout. Em um ambiente cloud, isso se dá por diversas razões, por exemplo:

Não há necessidade de escrever o log em arquivos pois o pod/container onde a aplicação está rodando vai rotacionar diversas vezes;
Existe um serviço (tipicamente elastic stack ou loki, por exemplo) agregando os logs;
logs estruturados são mais fáceis de transmitirem informação indexável ou contexto para a informação logada;

Se você já programou em java ou na jvm (kotlin, scala, clojure), é bem provavel que você já tenha visto ou ouvido falar do SLF4J que é um façade de log, permitindo que as bibliotecas e aplicações escrevam seus logs sem se preocupar com o backend que vai escrever eles no final. O mais famoso e usual de todos é o logback, desenvolvido e mantido pelo mesmo desenvolvedor do SLF4J.

É da minha experiência de escrever logs em json, com logback, que surge a vontade de escrever um novo backend de logs.

Em paralelo à isso, soma-se outro fator importante, que é a modernização da JVM. Nos últimos anos, é notável a mudança de postura do time da jdk quanto à releases, features e igualmente notável o quanto o java tem se modernizado. Entretanto, a comunidade é notoriamente morosa no processo de adoção das novas versões, com projetos novos saindo recentemente dando suporte à Java 8 (no momento da escrita do artigo, as versões atuais são Java 17 LTS e Java 20).

O projeto

A idéia de criar um backend alternativo para SLF4J é antiga na minha cabeça mas foi apenas quando a nova versão do SLF4J foi lançada, com suporte à fluent logging api, que eu resolvi colocar ela em prática. Isso porque o suporte atual à logs Json no logback se dá através de um projeto terceiro, logstash-logback-encoder, que na época não dava suporte à todas as novas features da versão 2.x do SLF4J.

Se você não conhece a fluent logging api da nova versão do SLF4J, ele se parece com isso:

var logger = LoggingFactory.getLogger("...");

logger.atInfo().addKeyValue("place", "tabnews").log("Olá!");

Como ficou evidente no exemplo acima, uma das vantagens da nova api é permitir a adição de informação na forma de chave-valor. Em muitos casos, isso permite uma melhor busca e indexação da informação, facilitando encontrar linhas de log quando muitas mensagens são escritas simultâneamente.

Portanto, os requisitos estavam prontos:

Suporte à nova API do SLF4J;
Logging estruturado em JSON;
Escrever direto para stdout;

Além disso, eu tinha alguns requisitos pessoais pra adicionar:

Alto desempenho;
Configuração padrão usável;
Usar versões modernas da JVM;

Definir requisitos e ser stakeholder e dev ao mesmo tempo

Aqui vai uma pausa pra falar de algo que eu considero importante quando falamos de open-source e projetos próprios. Nesse caso, eu sou o meu próprio PO, PM, Stakeholder do projeto, dev - e marketing, community manager, etc... - e definir prioridades ou requisitos do projeto não é tão simples quanto parece.
A regra de ouro aqui foi: Tem que ser minimamente divertido, empolgante, mas tem que trazer valor. Fazer o projeto ter alto desempenho é claramente um requisito artificial. Não é uma necessidade, porque o projeto por si só já traz valor. Entretanto, fazer o projeto ser necessariamente eficiente é um requisito que dá aquele desafio a mais que faz o humano por trás do teclado ter mais engajamento com o projeto. Ainda assim, existe um racional lógico de porque é importante ter alto desempenho e eu vou falar mais sobre isso abaixo. Nós podemos concordar que é um requisito ex-post, definido após o projeto ser desenhado, entretanto eu argumento que isso é uma coisa boa: Quando você é o dono do projeto, ele tem que ser interessante e trazer valor pra você antes de mais nada. O bônus é quando ele é útil para os outros. Na maior parte das vezes, o aprendizado e a experiência que vão ser obtidos com o projeto já o justificam.

Porque fazer algo com alta performance?

O argumento lógico e racional de porque fazer algo com alta performance talvez mereça um artigo próprio, mas vou tentar ser breve.

Quando você roda sua aplicação, a última coisa que você espera é que uma biblioteca terceira cause lentidões ou impedimentos no seu sistema. É de se esperar que uma biblioteca, em especial um backend de log, que você nem interage diretamente no seu código, vá ser discreta e não-obstrutiva.

Para falar de perfomance na JVM, é impossível deixar de falar sobre Garbage Collection: Em suma, algorítmos de GC fazem uma faxina na pilha de objetos alocados de tempos em tempos e quanto mais objetos desalocados, maior a chance de sua aplicação ter impacto. Isso é uma simplificação grosseira e, como eu disse, talvez todo esse tópico mereça um artigo próprio. Ainda assim, uma coisa que não queremos é que a biblioteca cause pressão no GC, incorrendo em pausas frequentes e baixo desempenho geral da sua aplicação.

Performance é um assunto delicado e toca em diversas questões que às vezes nem nos damos conta, como custo de data center, consumo de energia, necessidade de escalabilidade e mudanças arquiteturais. A última coisa que eu, enquanto mantenedor de uma biblioteca open source, quero, é impor restrições ou custos à quem usa a biblioteca.

Portanto, de maneira bem resumida, é justificável ir um pouco além pra obter bom desempenho.

Estado atual e futuro

Atualmente, penna está na versão 0.6.2 e esporadicamente tenho testado ele nos sistemas da empresa onde trabalho em produção. Uma versão 0.7 deve ser lançada em breve trazendo suporte à Elastic Common Schema e muitas outras features interessantes. Um website próprio (que merece o próprio post) também deve sair em breve.

Gostaria de ouvir opiniões e feedback.

Obrigado à todos e até a próxima!