rsyslog não está registrando

Question

Este é um problema estranho.

Eu estava testando os serviços de chrony / ntp em uma VM do RHEL7 e estava redefinindo seu tempo, assim como o do host. Assim que fiquei satisfeito, verifiquei /var/log/messages e percebi que não havia sido alterado em algum momento.

Agora, não importa o que eu faça, nada está sendo registrado, exceto quando eu reiniciar o próprio serviço rsyslog; quando eu obtenho isso:

Apr 15 13:59:43 mymachine1 rsyslogd: [origin software="rsyslogd" swVersion="7.4.2" x-pid="2847" x-info="http://www.rsyslog.com"] exiting on signal 2.

Apr 15 13:59:59 mymachine1 rsyslogd: [origin software="rsyslogd" swVersion="7.4.2" x-pid="2853" x-info="http://www.rsyslog.com"] start

Apr 15 14:00:11 mymachine1 rsyslogd-3000: sd_journal_get_cursor() failed: 'Cannot assign requested address'

Tentar coisas como logger test não registra, nada mais, a não ser as mensagens do rsyslog. Quando executo o rsyslog manualmente com -n -N1 como argumentos, obtenho:

rsyslogd: version 7.4.2, config validation run (level 1), master config /etc/rsyslog.conf

rsyslogd: End of config validation run. Bye

Parece que nada pode logar através do rsyslog por algum motivo. E uma segunda VM idêntica no mesmo host (que não passou pelo mesmo círculo de desabilitar repetidamente o ntp, tendo a data alterada e reinicializada várias vezes) com o mesmo arquivo rsyslog.conf.

Neste ponto, a data / hora está correta, o chrony está ativado e em execução e eu reiniciei várias vezes - depois de 30 segundos de mensagens do kernel, nada mais é registrado novamente.

Pensamentos?

    

Answer 1

Não é uma solução direta, mas eu permitia que alguns depurassem para ver o que está acontecendo nos bastidores.

Idéia # 1 - Agente de log de depuração

Para começar, quando você executa seus comandos logger , você pode fazê-los assim, ecoando mensagens para STDERR.

$ logger -s "hi"
saml: hi

Idéia # 2 - valide seu arquivo de configuração

Você também pode tentar validar seu arquivo de configuração do rsyslog:

$ sudo rsyslogd -N6 | head -10
rsyslogd: version 7.2.6, config validation run (level 6), master config /etc/rsyslog.conf
rsyslogd: End of config validation run. Bye.

6921.173842409:7f8b11df2780: rsyslogd 7.2.6 startup, module path '', cwd:/root
6921.175241008:7f8b11df2780: caller requested object 'net', not found (iRet -3003)
6921.175261977:7f8b11df2780: Requested to load module 'lmnet'
6921.175272711:7f8b11df2780: loading module '/lib64/rsyslog/lmnet.so'
6921.175505384:7f8b11df2780: module lmnet of type 2 being loaded (keepType=0).
6921.175520208:7f8b11df2780: entry point 'isCompatibleWithFeature' not present in module
6921.175528413:7f8b11df2780: entry point 'setModCnf' not present in module
6921.175535294:7f8b11df2780: entry point 'getModCnfName' not present in module
6921.175541502:7f8b11df2780: entry point 'beginCnfLoad' not present in module

Idéia # 3 - Aumente a depuração do rsyslogd

Além disso, tente ativar a depuração do daemon rsyslogd para obter mais informações.

$ sudo -i
$ export RSYSLOG_DEBUGLOG="/tmp/debuglog"
$ export RSYSLOG_DEBUG="Debug"

$ service rsyslog stop
$ rsyslogd -d | head -10    
7160.005597645:7fae096a3780: rsyslogd 7.2.6 startup, module path '', cwd:/root
7160.005872662:7fae096a3780: caller requested object 'net', not found (iRet -3003)
7160.005895004:7fae096a3780: Requested to load module 'lmnet'
7160.005906331:7fae096a3780: loading module '/lib64/rsyslog/lmnet.so'
7160.006023505:7fae096a3780: module lmnet of type 2 being loaded (keepType=0).
7160.006030872:7fae096a3780: entry point 'isCompatibleWithFeature' not present in module
7160.006033780:7fae096a3780: entry point 'setModCnf' not present in module
7160.006036209:7fae096a3780: entry point 'getModCnfName' not present in module
7160.006038359:7fae096a3780: entry point 'beginCnfLoad' not present in module
...
...
7160.006063913:7fae096a3780: rsyslog runtime initialized, version 7.2.6, current users 1
7160.006102179:7fae096a3780: source file syslogd.c requested reference for module 'lmnet', reference count now 2
7160.006113657:7fae096a3780: GenerateLocalHostName uses 'greeneggs'

Confirmando as informações da versão

$ rsyslogd -version
rsyslogd 7.2.6, compiled with:
    FEATURE_REGEXP:             Yes
    FEATURE_LARGEFILE:          No
    GSSAPI Kerberos 5 support:      Yes
    FEATURE_DEBUG (debug build, slow code): No
    32bit Atomic operations supported:  Yes
    64bit Atomic operations supported:  Yes
    Runtime Instrumentation (slow code):    No
    uuid support:               Yes

See http://www.rsyslog.com for more information.

Erro confirmado e uma solução alternativa

O OP enviou isso como um bug para a Red Hat.

• Bug 1088021 - Alterar o horário de um host da VM desativa o registro do arquivo rsyslog .

O bug foi caracterizado da seguinte forma:

Sure enough when I set the host's own time the VM had the same wrong time as the host. That's when I noticed /var/log/messages was no longer being updated.

It turns out nothing other than restarting the rsyslog service itself logs to files at that point. If I do so this gets logged:

  ---
   Apr 15 16:39:39 rhel7time-dev rsyslogd-3000: sd_journal_get_cursor() failed: 'Cannot assign requested address'

  Apr 15 16:39:39 rhel7time-dev rsyslogd: [origin software="rsyslogd" swVersion="7.4.2" x-pid="574" x-info="http://www.rsyslog.com"] exiting on signal 15.
  Apr 15 16:39:39 rhel7time-dev rsyslogd: [origin software="rsyslogd" swVersion="7.4.2" x-pid="2117" x-info="http://www.rsyslog.com"] start
  ---

Otherwise nothing is logged to file, including logger.

If I comment out $OmitLocalLogging on in rsyslog.conf then file logging resumes (notice that until that point I hadn't changed rsyslog.conf).

Logging through journal is unaffected by all this. journalctl -b shows logging, including anything sent by logger.

Para o qual o desenvolvedor respondeu:

When this issue occurs, you can delete /var/lib/rsyslog/imjournal.state and restart the daemon as a workaround.

rsyslog doesn't handle the date directly but only through the systemd API. I've checked the code in imjournal a while ago and this looks like an issue in systemd.

For reference, see: https://github.com/rsyslog/rsyslog/issues/43

    

Answer 2

No meu caso systemctl restart systemd-journald ajudou, porque

File /run/log/journal/29c32d60f93c42489aabb4ebeb593f5b/system.journal corrupted or uncleanly shut down, renaming and replacing.
[12274404.541271] systemd-journald[15492]: Deleted empty journal /run/log/journal/29c32d60f93c42489aabb4ebeb593f5b/[email protected]~ (4096 bytes).