☰

Exemplo: "Aplicativo sofisticado"

tag-icon • tag-icon logging monitoring systemd journald centralized-logging
Exemplo: "Aplicativo sofisticado"

Temos muitos aplicativos de produção (primários e de terceiros) que deixam o registro para o processo que executa o aplicativo e apenas registram stdoutpara INFOe stderrpara ERRORregistros (ou seja, apenas 2 prioridades de registro INFO|ERROR:).

Com uma unidade de serviço systemd para um aplicativo, isso pode ser configurado assim:

StandardOutput=journal
StandardError=journal

Isso permite que os devops gerenciem tudo por meio de unidades do systemd e do diário, a fim de facilitar a coleta centralizada de logs, monitorando tudo... e eles não precisam se preocupar em localizar e analisar diferentes logs em diferentes formatos/locais para cada aplicativo que implantam.

O diário do systemd possui um sistema de prioridade de mensagens compatível com o sistema de prioridade de mensagens de 7 níveis do syslog. INFOestá nivelado 6e ERRORestá nivelado 3. Veja referências para mais detalhes.

O problema é ... o systemd/journal aparentemente não distingue entre mensagens escritas no diário de stdout vs stderr. As mensagens stdout e stderr são todas gravadas no diário com prioridade padrão de 6 ( INFO).

Exemplo: "Aplicativo sofisticado"

/opt/log-test.sh

#!/bin/bash

echo "This is ERROR" 1>&2
echo "This is INFO"

exit 0

/etc/systemd/system/log-test.service

[Unit]
Description=log test for journal

[Service]
Type=simple

ExecStart=/opt/log-test.sh

StandardOutput=journal
StandardError=journal
SyslogIdentifier=log-test

execute-o e verifique o diário

$ systemctl start log-test
$ journalctl -u log-test
-- Logs begin at Thu 2022-04-07 08:17:16 UTC, end at Thu 2022-04-07 16:35:02 UTC. --
Apr 07 16:34:58 host.example.com systemd[1]: Started log test for journal.
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is ERROR
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is INFO
$ journalctl -u log-test -p 6   # syslog info priority
-- Logs begin at Thu 2022-04-07 08:17:16 UTC, end at Thu 2022-04-07 16:35:08 UTC. --
Apr 07 16:34:58 host.example.com systemd[1]: Started log test for journal.
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is ERROR
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is INFO
$ journalctl -u log-test -p 3   # syslog error priority
-- No entries --
$

Você pode ver que as mensagens stderr e stdout são definidas como prioridade 6( INFO) quando gravadas no diário.

Isso é um problema porque não temos uma maneira fácil de diferenciar a saída em stdout versus stderr ao usar stdio->journalcomo recurso de registro primário.

Isto tem sidodiscutido antesesoluçõessão possíveis, masnão implementado. Espero que a equipe do systemd eventualmente implemente isso, mas enquanto isso preciso de uma solução.

Alguém encontrou uma solução razoável para que as mensagens escritas em stdout e stderr sejam prioridades diferentes no diáriosem modificar a forma como um aplicativo faz o registro?

Não quero que todos os aplicativos que implantamos (nem todos escritos por nós) tenham que implementar integrações de diário ou syslog para obter prioridade de log quando realmente precisamos apenas de dois níveis: INFO(stdout) e ERROR(stderr).

Muito do que implantamos não é conteinerizado, portanto, depender dos recursos de registro do contêiner também não é uma solução para nós.

Ter o stderr e o stdout indo para o diário/syslog em prioridades diferentes por padrão é bastante crítico para facilitar o monitoramento de erros de log distribuído (assumindo uma boa higiene do desenvolvedor sobre apenas escrever coisas que precisam de atenção no stderr).

Referências:

Responder1

Se você tiver que usar stdout/ stderr, você pode usarsd-daemon prefixo de registro.

Anexe seu stderrcom <3>para enviar um log ERRORde prioridade journald.

Usando o seu log-test.she log-test.service:

#!/bin/bash

>&2 echo "<3>This is ERROR"
echo "This is INFO"

exit 0

E journalctlsaída:

$ journalctl -u log-test -p 3
May 02 01:22:58 host.example.com log-test.sh[29909]: This is ERROR

Se você fancy-apptiver alguma API para gravar syslog, poderá usá-la para gravar no datagrama UNIX /dev/log(geralmente gravável por padrão e registra em journald) em vez de stdout/ stderr. Use a tag syslog para identificar sua fancy-appprioridade de syslog errorou infodependendo de suas necessidades e qualquer recurso de syslog.

Por exemplo, no Bash podemos usarlogger:

# emit INFO message to journalctl
$ logger -t fancy-app -u /dev/log -p user.info "This is INFO"

# emit ERROR message to journalctl
$ logger -t fancy-app -u /dev/log -p user.error "This is ERROR"

# show journald messages for fancy-app
$ journalctl -t fancy-app
May 02 01:23:38 host.example.com fancy-app[27302]: This is INFO
May 02 01:23:39 host.example.com fancy-app[27303]: This is ERROR

# show journald ERROR messages for fancy-app
$ journalctl -t fancy-app -p 3
May 02 01:23:39 host.example.com fancy-app[27303]: This is ERROR

Observe que na maioria das distribuições journaldas entradas geralmente são encaminhadas para o daemon syslog local ( syslog-ng, rsyslog, ...), então provavelmente verifique seus filtros syslog ou talvez use local0... local7recursos.

Temos muitos aplicativos de produção (primários e de terceiros) que deixam o registro no contêiner e apenas registram em stdout para INFO e stderr para logs de ERRO (ou seja, apenas 2 prioridades de log: INFO | ERROR).

A maioria dos mecanismos de contêiner deve ser capaz de registrar no syslog. Sem conhecer seu mecanismo de contêiner, usarei o Docker como exemplo.

Docker temdriver de registro syslogque pode ser usado para enviar mensagens de log usando o formato syslog para qualquer destino syslog. Você deve conseguir fazer login journaldcom algo como:

docker run \
    --log-driver syslog \
    --log-opt syslog-address=unix:///dev/log \
    --log-opt syslog-facility=user \
    --log-opt tag=fancy-app \
    fancy-app:latest

Docker também temdriver de registro do journalddisponível. Por exemplo:

docker run \
    --log-driver journald \
    --log-opt tag=fancy-app \
    fancy-app:latest

Ambos os drivers de registro (registro de sistemaediário) suporta separação entre stdoute stderr; ou seja , stdoutas mensagens serão registradas com INFOprioridade e stderras mensagens serão registradas com ERRORprioridade.

Deixando de lado as filosofias e as guerras violentas, por que não logar no syslog real? É mais fácil, armazenado em formato de texto e geralmente suportado por softwares de gerenciamento de logs (vejaGraylog,Logstash,Trilha de papel).

informação relacionada