TL; DR
Se você estiver interessado apenas em determinar qual processo gerou uma determinada mensagem em /var/log/messages , observe a primeira parte de cada linha. Isso mostra o nome do processo junto com o PID de quem gerou uma determinada linha. Nos exemplos abaixo, fprintd , PID 444 e gnome-session , PID 8316 geraram essas linhas no meu messages log.
Feb 18 23:07:20 greeneggs fprintd[444]: ** Message: No devices in use, exit
Feb 18 23:08:53 greeneggs gnome-session[8316]: 23:08:53 | Git | personal_repo | Checking for remote changes...
Feb 18 23:08:53 greeneggs gnome-session[8316]: 23:08:53 | Cmd | personal_repo | git rev-parse HEAD
Analisando as gravações
Os processos não são gravados diretamente em /var/log/messages , em vez disso, eles precisam enviar as mensagens para rsyslogd , que gerenciam a gravação de mensagens nesse arquivo de log. Isso fica evidente se você usar o comando lsof para ver quais arquivos são abertos no diretório /var/log por rsyslogd .
$ sudo lsof -p $(pgrep syslogd) | grep '/var/log'
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
Output information may be incomplete.
rsyslogd 733 root 5w REG 253,1 11413306 1323777 /var/log/messages
rsyslogd 733 root 6w REG 253,1 61714 1318348 /var/log/cron
rsyslogd 733 root 7w REG 253,1 60103 1323778 /var/log/secure
rsyslogd 733 root 8w REG 253,1 49725 1323776 /var/log/maillog
Podemos ver com strace?
Portanto, uma abordagem seria ver quais processos gravam em rsyslogd , em vez do arquivo de log messages diretamente. Para fazer isso, primeiro precisamos determinar os PIDs de todos os threads rsyslogd .
$ sudo ps -eLf | grep rsyslogd
root 733 1 733 0 4 Feb17 ? 00:00:00 /sbin/rsyslogd -n
root 733 1 795 0 4 Feb17 ? 00:00:01 /sbin/rsyslogd -n
root 733 1 796 0 4 Feb17 ? 00:00:00 /sbin/rsyslogd -n
root 733 1 798 0 4 Feb17 ? 00:00:01 /sbin/rsyslogd -n
root 27863 23659 27863 0 1 22:14 pts/2 00:00:00 grep --color=auto rsyslogd
Com os PIDs em mãos, você pode usar strace para ver como os registros são gravados em rsyslogd . Isso é um pouco de tentativa e erro, mas consegui strace este PID e, em seguida, usar logger para simular a atividade no meu arquivo de log /var/log/messages .
Exemplo
$ sudo strace -p 795 -s 2000 -o rsyslogd.log
Agora escrevo uma mensagem usando logger :
$ logger hey
Se assistirmos ao nosso arquivo de log strace , rsyslogd.log , veremos esse tipo de mensagem como resultado:
$ sudo tail -f rsyslogd.log
select(4, [3], NULL, NULL, NULL) = 1 (in [3])
recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"<13>Feb 18 22:15:49 saml: hey", 8096}], msg_controllen=0, msg_flags=MSG_CTRUNC}, MSG_DONTWAIT) = 29
futex(0x7f41ba963d14, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f41ba963d10, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
futex(0x7f41ba963e70, FUTEX_WAKE_PRIVATE, 1) = 1
select(4, [3], NULL, NULL, NULL
Se nós strace todos os rsyslogd PIDs, registrando todos os seus resultados em diferentes arquivos de log ( me*.log onde * = 1-4) e então tail -f me*.log , agora teremos uma visão expandida de nosso logger hey comando:
==> me1.log <==
) = 1 (in [3])
recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"<13>Feb 18 22:23:23 saml: hey", 8096}], msg_controllen=0, msg_flags=MSG_CTRUNC}, MSG_DONTWAIT) = 29
futex(0x7f41ba963d14, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f41ba963d10, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
==> me3.log <==
) = 0
==> me1.log <==
select(4, [3], NULL, NULL, NULL
==> me3.log <==
futex(0x7f41ba963e70, FUTEX_WAKE_PRIVATE, 1) = 0
write(5, "Feb 18 22:23:23 greeneggs saml: hey\n", 36) = 36
futex(0x7f41ba963d14, FUTEX_WAIT_PRIVATE, 67373, NULL
Podemos ver um pouco mais do que está acontecendo, mas ainda não conseguimos identificar exatamente qual processo gerou a mensagem para rsyslogd .
Que tal usar o fatrace?
Esta é uma nova adição ao conjunto de ferramentas de rastreamento, mas pode ser muito útil em situações como a sua. Você pode rastrear todo o acesso de E / S de arquivos em todo o sistema usando essa ferramenta, mas podemos restringir seu foco apenas ao diretório /var/log para ver se não podemos descobrir qual processo está enviando mensagens de log para rsyslogd .
Exemplo
Para começar, executaríamos esse comando para assistir apenas /var/log messages.
$ sudo fatrace | grep /var/log
Agora, quando os processos começarem a acessar /var/log , obteremos um fluxo constante de qual processo está fazendo o acesso.
Aqui está a saída quando executei este comando, sudo -i :
systemd-journal(340): O /var/log/journal/0ee868f8b7da40f48013a281826b1b84
systemd-journal(340): C /var/log/journal/0ee868f8b7da40f48013a281826b1b84
rsyslogd(733): W /var/log/secure
rsyslogd(733): W /var/log/secure
auditd(546): W /var/log/audit/audit.log
auditd(546): W /var/log/audit/audit.log
auditd(546): W /var/log/audit/audit.log
Aqui está a raiz ssh 'na caixa via localhost, ssh root@localhost :
auditd(546): W /var/log/audit/audit.log
auditd(546): W /var/log/audit/audit.log
rsyslogd(733): W /var/log/messages
rsyslogd(733): W /var/log/messages
rsyslogd(733): W /var/log/secure
sshd(23718): O /var/log/lastlog
rsyslogd(733): W /var/log/secure
sshd(23718): RC /var/log/lastlog
sshd(23718): RCO /var/log/btmp
auditd(546): W /var/log/audit/audit.log
sshd(23724): RCO /var/log/lastlog
sshd(23724): O /var/log/wtmp
sshd(23724): W /var/log/wtmp
sshd(23724): W /var/log/wtmp
sshd(23724): CW /var/log/wtmp
sshd(23724): CW /var/log/wtmp
sshd(23724): CWO /var/log/lastlog
sshd(23724): CW /var/log/lastlog
Usar o fatrace pode ajudá-lo a começar a identificar qual processo está direcionando as mensagens de log para /var/log/messages .
Como as mensagens chegam ao / var / log / messages?
Se você pegar algo como SSH, o daemon, sshd , será configurado por este arquivo de configuração, /etc/ssh/sshd_config . Existe essa linha nesse arquivo que especifica onde sshd deve enviar suas mensagens do arquivo de log.
# Logging
# obsoletes QuietMode and FascistLogging
#SyslogFacility AUTH
SyslogFacility AUTHPRIV
#LogLevel INFO
Portanto, isso significa que sshd está fazendo uso do SyslogFacility e suas únicas mensagens de envio que são AUTHPRIV ou superiores. Então, como as mensagens chegam em /var/log/messages ?
Dê uma olhada no arquivo de configuração rsyslogd , /etc/rsyslog.conf :
# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none /var/log/messages
OBSERVAÇÃO: Observe o authpriv no lado esquerdo? Isso é o que "encaminha" as mensagens de sshd para o arquivo, /var/log/messages .