Essa tarefa trivial surgiu em uma tarde de sexta-feira e deveria levar de 2 a 3 minutos. Em geral, como sempre.
Um colega me pediu para consertar o script em seu servidor. Eu fiz isso, entreguei a ele e inadvertidamente deixei cair: “O tempo está 5 minutos rápido”. Deixe o servidor cuidar da sincronização sozinho. Meia hora, uma hora se passou, e ele ainda bufava e praguejava baixinho.
"Estúpido! — pensei, mudando para o console do servidor — ok, vou fazer uma pausa por mais alguns minutos.”
Veja ntp, rdate, sdwdate não instalado sincronização de tempo desabilitado e não funcionando.
# 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 observarei imediatamente que o horário do hardware está correto: será mais fácil navegar mais.
Foi aqui que começou a série de erros.
O primeiro erro. Auto confiança
Clique-clique...
# 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, a hora está sincronizada, a hora do sistema corresponde à do hardware. “Pegue”, eu disse e voltei ao meu negócio.
"Tomar o que? - o colega ficou indignado. “É a mesma hora!”
Quanto mais você resolve problemas típicos, mais seu pensamento fica cego e você não pensa mais 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á errada novamente.
Vamos tentar de novo:
# 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 para uma fração de segundo e imediatamente começa a “acelerar” novamente.
Ao mesmo tempo, nos logs, no momento de tal alteração manual, vemos apenas relatórios do sistema de que a hora 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
A essa altura já era preciso procurar o motivo, mas ao longo de 18 anos de administração, o cérebro acumulou estatísticas de erros de “tempo” e, por hábito, volta a culpar a sincronização.
Vamos desligar 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 registros
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
Ressincronizando desapareceu e, caso contrário, os logs estão imaculados.
Verificando as conclusões tcpdump na porta 123 em todas as interfaces. Não há pedidos, mas o tempo ainda está correndo.
Erro dois. Correr
Falta uma hora para o final da semana de trabalho, e não quero sair para o fim de semana com um problema trivial sem solução (não preste atenção no horário no código, o artigo foi escrito nos dias seguintes ).
E aqui novamente, em vez de procurar o motivo, comecei a tentar encontrar uma explicação para o resultado. Digo “inventar” porque não importa quão lógica seja a explicação para o resultado, é uma abordagem falha para resolver o problema.
Este servidor é um servidor de streaming e converte o stream DVB-S2 em IP. O fluxo DVB-S contém carimbos de data e hora, portanto, receptores, multiplexadores, codificadores e televisores costumam usá-los para sincronizar o relógio do sistema. Os drivers da placa DVB-S estão integrados no kernel, portanto a maneira mais rápida de garantir que o fluxo DVB-S2 seja removido é desconectar os cabos provenientes das “placas”. Felizmente, o servidor está atrás da parede, que assim seja.
É claro que se os logs contivessem o que deveria estar lá, isso não teria acontecido, mas mais sobre isso, novamente, no final do artigo.
Bem, como já removemos todos os sinais de satélite, removeremos também os terrestres - ao mesmo tempo que retiramos todos os cabos de rede. O servidor fica isolado do mundo exterior 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 em si não é crítica, então você pode simplesmente ir para casa, mas aqui cometo um novo erro.
Erro três. Conselheiros
Nunca! Nunca faça perguntas em fóruns e sites especializados em geral (a la stackoverflow) se a resposta exigir mais do que estudar a primeira página do Google e ler uma página de manual.
Eles vão te mandar de volta ao Google, ler o mesmo homem e explicar popularmente as regras do fórum/site, mas não vão te dar uma resposta.
Aqui estão alguns fatores objetivos:
- ninguém, exceto você, também pode conhecer o problema;
- ninguém pode realizar testes nas mesmas condições que os seus
e subjetivo:
- você pode não dar todos os subsídios para a resolução do problema, pois já traçou a direção “certa” e está apresentando a essência do problema focando nele;
- o capataz (moderador, veterano, administrador) sempre tem razão, se o capataz estiver errado... bem, você sabe...
Se, ao responder aos comentários, você permaneceu dentro dos limites do vocabulário censurado, então você está com os nervos à flor da pele.
Solução
Não há necessidade de dividir as tarefas em simples e complexas.
Deixamos de confiar na nossa experiência, estatísticas, consultores e passamos a não “explicar” o resultado final, mas a procurar consistentemente o motivo.
Como alguém define a hora, a chamada do sistema correspondente deve ocorrer.
Assim como na documentação de software os melhores documentos são as fontes, na administração de sistemas o melhor assistente é a auditoria, no nosso caso auditado.
Um momento de dúvidaPassei pelo mana, mas não tinha certeza se o tempo no Linux só pode ser definido hora_relógio и hora marcada, então para o primeiro teste escolhi 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_createqual auditctl não o reconheceu, inicialmente lançou uma 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 utimesDepois de me certificar de que não há outros registros nos locais de registro nos quais estou interessado chamadas de sistema Além desses dois, usei apenas eles ainda mais.
Executando uma auditoria de chamada do sistema hora_relógio и hora marcada e tente alterar a data:
# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D
Um atraso de cinco segundos é adicionado para que nosso “parasita” tenha a garantia de corrigir 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 o nosso dados e desconhecido para nós chkcache_processes. Acabou no relatório acima porque o aureport classificou a saída por data ao converter do binário, e o evento ocorreu no momento que definimos data -s "2019/08/22 12:10:00".
Quem deu à luz a 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 do seu comportamento “malicioso”, é impossível recusar o sistema de acesso condicional, mas ainda assim gostaria de saber oscam, O que é isso?
A resposta é rapidamente encontrada em :
#if defined(CLOCKFIX)
if (tv.tv_sec > lasttime.tv_sec || (tv.tv_sec == lasttime.tv_sec && tv.tv_usec >= lasttime.tv_usec)) // check for time issues!
{
lasttime = tv; // register this valid time
}
else
{
tv = lasttime;
settimeofday(&tv, NULL); // set time back to last known valid time
//fprintf(stderr, "*** WARNING: BAD TIME AFFECTING WHOLE OSCAM ECM HANDLING, SYSTEMTIME SET TO LAST KNOWN VALID TIME **** n");
}
Que fofo parece aqui comentado linha aviso...
Fonte: habr.com