Essa tarefa trivial surgiu em um dos dias de sexta-feira e deveria levar de 2 a 3 minutos. Em geral, como sempre.
Um colega me pediu para corrigir o script no servidor dele. Ele fez, entregou a ele e largou-o inadvertidamente: "O tempo está com pressa por 5 minutos". Seu servidor, mesmo que ele entenda a sincronização. Meia hora, uma hora se passou, e ele bufa e xinga baixinho.
“Confunda! - pensei, mudando para o console do servidor - bem, vou sair por mais alguns minutos. ”
Observamos que
ntp, rdate, sdwdate não
estão instalados, o
timesyncd está desativado e não está em execução.
# timedatectl Local time: Sun 2019-08-25 20:44:39 +03 Universal time: Sun 2019-08-25 17:44:39 UTC RTC time: Sun 2019-08-25 17:39:52 Time zone: Europe/Minsk (+03, +0300) NTP enabled: no NTP synchronized: no RTC in local TZ: no DST active: n/a
Aqui, observo imediatamente que o tempo do hardware está correto: será mais fácil navegar mais nele.
A partir daqui, uma série de erros começou.
Primeiro erro. Autoconfiança
Klats-klats ...
# systemctl enable systemd-timesyncd.service && systemctl start systemd-timesyncd.service && ntpdate 0.ru.pool.ntp.org && timedatectl set-ntp on && timedatectl 25 Aug 21:00:10 ntpdate[28114]: adjust time server 195.210.189.106 offset -249.015251 sec Local time: Sun 2019-08-25 21:00:10 +03 Universal time: Sun 2019-08-25 18:00:10 UTC RTC time: Sun 2019-08-25 18:00:10 Time zone: Europe/Minsk (+03, +0300) NTP enabled: yes NTP synchronized: yes RTC in local TZ: no DST active: n/a
Está tudo bem, o tempo foi sincronizado, o sistema coincide com o hardware. "Pegue", eu larguei e voltei ao meu negócio.
"O que levar embora?" - o colega ficou indignado. "Os velhos tempos!"
Quanto mais você resolve problemas típicos, mais o seu pensamento começa e você não acha que a centésima ou milésima situação será diferente, mas não desta vez.
# timedatectl Local time: Sun 2019-08-25 21:09:15 +03 Universal time: Sun 2019-08-25 18:09:15 UTC RTC time: Sun 2019-08-25 18:05:04 Time zone: Europe/Minsk (+03, +0300) NTP enabled: yes NTP synchronized: no RTC in local TZ: no DST active: n/a
A hora do sistema está novamente incorreta.
Vamos tentar novamente:
# ntpdate 0.ru.pool.ntp.org && timedatectl && sleep 1 && timedatectl 25 Aug 21:07:37 ntpdate[30350]: step time server 89.175.20.7 offset -249.220828 sec Local time: Sun 2019-08-25 21:07:37 +03 Universal time: Sun 2019-08-25 18:07:37 UTC RTC time: Sun 2019-08-25 18:07:37 Time zone: Europe/Minsk (+03, +0300) NTP enabled: yes NTP synchronized: yes RTC in local TZ: no DST active: n/a Local time: Sun 2019-08-25 21:11:46 +03 Universal time: Sun 2019-08-25 18:11:46 UTC RTC time: Sun 2019-08-25 18:07:37 Time zone: Europe/Minsk (+03, +0300) NTP enabled: yes NTP synchronized: no RTC in local TZ: no DST active: n/a
Vamos fazer diferente:
# date -s "2019-08-25 21:10:30" && date && sleep 1 && timedatectl Sun Aug 25 21:10:30 +03 2019 Sun Aug 25 21:10:30 +03 2019 Local time: Sun 2019-08-25 21:14:36 +03 Universal time: Sun 2019-08-25 18:14:36 UTC RTC time: Sun 2019-08-25 18:10:30 Time zone: Europe/Minsk (+03, +0300) NTP enabled: yes NTP synchronized: no RTC in local TZ: no DST active: n/a
E assim:
# hwclock --hctosys && timedatectl && sleep 1 && timedatectl Local time: Sun 2019-08-25 21:11:31 +03 Universal time: Sun 2019-08-25 18:11:31 UTC RTC time: Sun 2019-08-25 18:11:31 Time zone: Europe/Minsk (+03, +0300) NTP enabled: yes NTP synchronized: yes RTC in local TZ: no DST active: n/a Local time: Sun 2019-08-25 21:15:36 +03 Universal time: Sun 2019-08-25 18:15:36 UTC RTC time: Sun 2019-08-25 18:11:32 Time zone: Europe/Minsk (+03, +0300) NTP enabled: yes NTP synchronized: no RTC in local TZ: no DST active: n/a
O tempo é definido por uma fração de segundo e começa a "acelerar" novamente.
Ao mesmo tempo, nos logs, no momento de uma alteração manual, vemos apenas o sistema relatar que o tempo mudou, respectivamente, na direção certa / errada e, ocasionalmente,
ressincronizando do systemd-timesyncd.
Aug 25 21:18:51 wisi systemd[1]: Time has been changed Aug 25 21:18:51 wisi systemd-timesyncd[29258]: System time changed. Resyncing. Aug 25 21:18:51 wisi systemd[1187]: Time has been changed Aug 25 21:18:51 wisi systemd[1]: Time has been changed Aug 25 21:18:51 wisi systemd[1187]: Time has been changed
aqui
# ps afx | grep "[1]187" 1187 ? Ss 0:02 /lib/systemd/systemd --user
Nesse ponto, já era necessário procurar a causa, mas o cérebro durante 18 anos de administração desenvolveu estatísticas de erros de "tempo" e, por hábito, novamente culpa a sincronização.
Desligue-o completamente.
# timedatectl set-ntp off && systemctl stop systemd-timesyncd.service # hwclock --hctosys && timedatectl && sleep 1 && timedatectl Local time: Sun 2019-08-25 21:25:40 +03 Universal time: Sun 2019-08-25 18:25:40 UTC RTC time: Sun 2019-08-25 18:25:40 Time zone: Europe/Minsk (+03, +0300) NTP enabled: no NTP synchronized: no RTC in local TZ: no DST active: n/a Local time: Sun 2019-08-25 21:29:31 +03 Universal time: Sun 2019-08-25 18:29:31 UTC RTC time: Sun 2019-08-25 18:25:41 Time zone: Europe/Minsk (+03, +0300) NTP enabled: no NTP synchronized: no RTC in local TZ: no DST active: n/a
e nos logs
Aug 25 21:25:40 wisi systemd[1]: Time has been changed Aug 25 21:25:40 wisi systemd[1187]: Time has been changed Aug 25 21:29:30 wisi systemd[1]: Time has been changed Aug 25 21:29:30 wisi systemd[1187]: Time has been changed
A ressincronização acabou e o restante dos logs está intocado.
Verificamos as saídas do
tcpdump na 123rd porta em todas as interfaces. Não há pedidos, mas o tempo também está acabando.
O segundo erro. Pressa
Há uma hora restante até o final da semana de trabalho, mas você não deseja sair para o final de semana com uma tarefa ruim (não preste atenção ao horário no código, o artigo foi escrito nos dias seguintes).
E aqui novamente, em vez de procurar um motivo, comecei a tentar apresentar uma explicação para o resultado. Eu digo "invente", porque não importa quão lógicas sejam as explicações para o resultado, essa é uma abordagem incorreta para resolver o problema.
Este servidor está transmitindo e converte o fluxo DVB-S2 em IP. Existem registros de data e hora no fluxo DVB-S; portanto, receptores, multiplexadores, codificadores e televisores costumam usá-los para sincronizar o relógio do sistema. Os drivers para placas DVB-S são compilados no kernel; portanto, a maneira mais rápida de garantir um fluxo DVB-S2 limpo é desconectar os cabos provenientes das "placas". Felizmente, portanto, o servidor está atrasado.
Obviamente, se os logs tivessem o que deveria estar lá, isso não teria acontecido, mas mais sobre isso, novamente, no final do artigo.
Bem, como já excluímos todos os sinais de satélite, também removeremos os terrestres - ao longo do caminho, retiramos todos os cabos da rede. O servidor fica isolado do mundo externo e funciona de forma totalmente autônoma, mas o relógio do sistema ainda está com pressa.
A semana de trabalho acabou, e a questão da data / hora não é crítica, então você pode simplesmente ir para casa, mas aqui eu cometo um novo erro.
O terceiro erro. Assessores
Nunca! Nunca faça perguntas em fóruns e sites geralmente especializados (à la stackoverflow) se a resposta exigir mais do que estudar a emissão da primeira página do Google e ler uma página de man'a.
Você será enviado de volta ao google, lerá o mesmo homem e explicará popularmente as regras do fórum / site, mas não dará uma resposta.
Existem dois fatores objetivos:
- ninguém, exceto você, também pode conhecer o problema;
- ninguém pode testar nas mesmas condições que você
e subjetivo:
- você pode não fornecer todas as informações para resolver o problema, porque já criou a direção “certa” e afirma a essência do problema, apoiando-se nele;
- capataz (moderador, veterano, administrador) está sempre certo se o capataz estiver errado ... bem, você sabe ...
Se, em resposta aos comentários, você permaneceu no quadro do vocabulário da censura, então você tem nervos fortes.
Solução
Não há necessidade de dividir tarefas em simples e complexas.
Paramos de confiar em nossa experiência, estatísticas, consultores e começamos a não "explicar" o resultado final, mas a procurar consistentemente o motivo.
Depois que alguém define o horário, uma chamada de sistema apropriada deve ocorrer.
Como na documentação do software, as melhores docas são as fontes; portanto, na administração do sistema, o melhor assistente é a auditoria, no nosso caso, a
auditoria .
Momento de dúvidaEu corri através do homem, mas não tinha certeza absoluta de que o relógio no Linux só pode ser ajustado por
clock_settime e
settimeofday , portanto, no primeiro teste, selecionei todas as chamadas "adequadas":
# man syscalls | col | grep -F '(2)' | grep -vE '(:|;)' | grep -E '(time|date|clock)' | sed "s/(2).*//" | xargs -I SYSCALL echo "-S SYSCALL " | xargs echo -S adjtimex -S clock_adjtime -S clock_getres -S clock_gettime -S clock_nanosleep -S clock_settime -S futimesat -S getitimer -S gettimeofday -S mq_timedreceive -S mq_timedsend -S rt_sigtimedwait -S s390_runtime_instr -S setitimer -S settimeofday -S stime -S time -S timer_create -S timer_delete -S timer_getoverrun -S timer_gettime -S timer_settime -S timerfd_create -S timerfd_gettime -S timerfd_settime -S times -S utime -S utimensat -S utimes
e descartando
s390_runtime_instr, stime, timerfd_create , que o
auditctl não reconheceu, iniciou inicialmente a auditoria no formato:
auditctl -a exit,always -S adjtimex -S clock_adjtime -S clock_getres -S clock_nanosleep -S clock_settime -S futimesat -S getitimer -S gettimeofday -S mq_timedreceive -S mq_timedsend -S rt_sigtimedwait -S semtimedop -S setitimer -S settimeofday -S time -S timer_create -S timer_delete -S timer_getoverrun -S timer_gettime -S timer_settime -S timerfd_gettime -S timerfd_settime -S times -S utime -S utimensat -S utimes
Depois de me certificar de que, nos locais dos logs que me interessam, não há outros
syscalls além desses dois, usei apenas eles.
Iniciamos a auditoria das chamadas do sistema
clock_settime e
settimeofday e tentamos alterar a data:
# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D
Foi adicionado um atraso de cinco segundos para garantir que o nosso "parasita" corrija a hora.
Analisamos o relatório:
# aureport -s -i Syscall Report ======================================= # date time syscall pid comm auid event ======================================= Warning - freq is non-zero and incremental flushing not selected. 1. 08/22/2019 12:10:00 settimeofday 3088 chkcache_proces root 479630 2. 08/26/2019 09:37:06 clock_settime 1538 date root 479629
Aqui vemos a nossa
data e desconhecida para nós
chkcache_proces . Acabou por constar no relatório acima, já que o aureport classificou a saída por data ao converter a partir da visualização binária, e o evento ocorreu no momento em que definimos a
data -s “2019-08-22 12:10:00” .
Quem deu à luz ele?
# ausearch -sc settimeofday --comm "chkcache_proces" ---- time->Thu Aug 22 12:10:00 2019 type=PROCTITLE msg=audit(1566465000.000:479630): proctitle="/usr/local/bin/oscam" type=SYSCALL msg=audit(1566465000.000:479630): arch=c000003e syscall=164 success=yes exit=0 a0=7fde0dfc6e60 a1=0 a2=136cf a3=713ba56 items=0 ppid=3081 pid=3088 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts20 ses=68149 comm="chkcache_proces" exe="/usr/local/bin/oscam" key=(null)
/ usr / local / bin / oscam - nosso parasita foi encontrado. Apesar de seu comportamento "malicioso", é impossível abandonar o sistema de acesso condicional, mas ainda gostaria de saber,
oscam , WTF?
A resposta é encontrada rapidamente na
fonte :
#if defined(CLOCKFIX) if (tv.tv_sec > lasttime.tv_sec || (tv.tv_sec == lasttime.tv_sec && tv.tv_usec >= lasttime.tv_usec))
Como é agradável a linha de
aviso comentada aqui ...