ProHoster > Blog > Administração > Quanto mais simples a tarefa, mais frequentemente eu erro

Quanto mais simples a tarefa, mais frequentemente eu erro

Quanto mais simples a tarefa, mais frequentemente eu erro

Essa tarefa trivial surgiu em uma das sextas-feiras e deveria levar de 2 a 3 minutos. No geral, como sempre.

Um colega pediu para corrigir um script no servidor dele. Fiz, entreguei a ele e deixei escapar: "O tempo está adiantado em 5 minutos". O servidor dele, que se vire com a sincronização. Meia hora, uma hora se passou, e ele ainda está lá, suando e xingando baixinho.

"Idiota!" — pensei, mudando para o console. servidor — bem, vou me deter por mais alguns minutos.

Vamos ver, ntp, rdate, sdwdate não estão instalados, timesyncd está desativado e não iniciado.

# 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, já vou notar que o tempo de hardware está correto: isso facilitará a referência posteriormente.

Daqui começaram uma série de erros.

Erro um. Autoconfianç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

Tudo ótimo, o tempo sincronizou, o tempo do sistema coincide com o de hardware. "Leve", - deixei escapar e voltei ao que estava fazendo.

"O que levar?" — se indignou o colega. — "O tempo é o mesmo!"

Quanto mais você resolve tarefas típicas, mais sua mente fica estreita e você não pensa 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

O tempo do sistema novamente está incorreto.

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 em uma fração de segundo e logo começa a "adiantar" novamente.

Neste momento, nos logs, na ocasião de tal alteração manual, vemos apenas relatórios do sistema, de que o tempo mudou, respectivamente em direções corretas/incorretas e ocasionalmente Resincronizando do systemd-timesyncd.

25 de ago 21:18:51 wisi systemd[1]: O tempo foi alterado
25 de ago 21:18:51 wisi systemd-timesyncd[29258]: O tempo do sistema foi alterado. Resincronizando.
25 de ago 21:18:51 wisi systemd[1187]: O tempo foi alterado
25 de ago 21:18:51 wisi systemd[1]: O tempo foi alterado
25 de ago 21:18:51 wisi systemd[1187]: O tempo foi alterado

aqui

# ps afx | grep "[1]187"
 1187 ?        Ss     0:02 /lib/systemd/systemd --user

Nesse momento, já era preciso procurar a causa, mas o cérebro, após 18 anos de administração, já acumulou a estatística dos erros de "tempo" e, por hábito, culpa novamente a sincronização.
Desconectamos 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

25 de ago 21:25:40 wisi systemd[1]: O tempo foi alterado
25 de ago 21:25:40 wisi systemd[1187]: O tempo foi alterado
25 de ago 21:29:30 wisi systemd[1]: O tempo foi alterado
25 de ago 21:29:30 wisi systemd[1187]: O tempo foi alterado

Resincronizando desapareceu e os demais logs estão imaculadamente limpos.

Verificamos as saídas tcpdump pelo porta 123 em todas as interfaces. Não há nenhuma solicitação, mas o tempo ainda assim "foge".

Erro dois. Pressa

Faltam apenas uma hora até o fim da semana de trabalho, e eu não quero sair para o fim de semana com uma tarefa não resolvida (não preste atenção ao tempo no código, o artigo foi escrito nos dias seguintes).
E aqui novamente, em vez de buscar a causa, comecei a tentar criar uma explicação para o resultado. Digo 'criar', porque apesar de as explicações do resultado serem lógicas, essa é uma abordagem errônea para resolver o problema.

Este servidor é de streaming e converte o fluxo DVB-S2 em IP. No fluxo DVB-S, existem marcas de tempo, portanto receptores, multiplexadores, descrambadores e TVs frequentemente as utilizam para sincronizar os relógios do sistema. Os drivers das placas DVB-S estão compilados no kernel, portanto a maneira mais rápida de remover garantidamente o fluxo DVB-S2 é desconectar os cabos que vão das 'antenas'. Felizmente, o servidor está do outro lado da parede, então assim deve ser.

Claro, se os logs contivessem o que deveriam, isso não teria acontecido, mas sobre isso, novamente, no final do artigo.

Bem, uma vez que já removemos todos os sinais de satélite, vamos remover também os terrestres — ao mesmo tempo, desconectamos todos os cabos de rede. O servidor fica isolado do mundo externo e opera de forma absolutamente autônoma, mas os relógios do sistema ainda avançam.

A semana de trabalho terminou, e a questão da data/hora não é crítica, portanto posso 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 (como o Stack Overflow) se a resposta exigir mais do que estudar os resultados da primeira página do Google e ler uma página do manual.

Você será enviado de volta ao Google, para ler aquele mesmo manual e receberá explicações populares sobre as regras do fórum/site, mas não receberá a resposta.

Aqui existem tanto fatores objetivos:

  • ninguém além de você pode entender o problema tão bem;
  • ninguém pode realizar testes nas mesmas condições que você;

quanto fatores subjetivos:

  • você pode não fornecer todas as informações necessárias para a resolução do problema, porque já придумou uma 'direção correta' e baseia a essência da pergunta nele;
  • o sargento (moderador, veterano, admin) sempre está certo, se o sargento estiver errado... bem, você sabe...

Se ao responder a comentários você se manteve dentro dos limites da linguagem adequada, então você tem nervos fortes.

Solução

Não é necessário dividir as tarefas em simples e complexas.

Vamos parar de confiar em nossa experiência, estatísticas, conselheiros e começar a não 'explicar' o resultado final, mas buscar a causa de forma sequencial.

Se alguém está definindo o tempo, deve ocorrer a chamada do sistema correspondente.

Assim como na documentação do software os melhores documentos são os códigos-fonte, na administração de sistemas o melhor auxiliar é a auditoria, neste caso. auditd.

Um momento de dúvidaRevisei os manuais, mas não estava completamente certo de que o tempo no Linux poderia ser configurado apenas por clock_settime e settimeofday, 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_create, que não reconheci, eu inicialmente inicie a auditoria na forma de: auditctl 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

Certificando-me de que não havia outras

syscalls além desses dois, utilizei apenas eles. Iniciamos a auditoria das chamadas de sistema

e tentamos mudar a data: clock_settime e settimeofday Uma pausa de cinco segundos foi adicionada para que nosso 'parasita' garantisse a correção do tempo.

# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D

Vejamos o relatório:

Aqui vemos nosso

# 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

e desconhecido para nós date chkcache_proces . Ele apareceu no relatório acima, pois o aureport ordenou a saída pela data ao converter de formato binário, e o evento ocorreu na hora que configuramosdate -s '2019-08-22 12:10:00' Quem o originou?.
— nosso parasita foi encontrado. Apesar de seu comportamento 'malicioso', não podemos nos desfazer do sistema de acesso condicional, mas ainda assim gostaríamos de saber,

# 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 oscam , WTF?A resposta foi rapidamente encontrada em

Como este trecho se apresenta tão bonitinho código-fonte:

#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");
}

linhas comentadas de warning Essa tarefa trivial surgiu em uma das sextas-feiras. 🥇 Quanto mais simples a tarefa, mais frequentemente erro | ProHoster…

Fonte: habr.com

Compre hospedagem confiável para sites com proteção contra DDoS, servidores VPS VDS 🔥 Compre hospedagem confiável para sites com proteção contra DDoS, servidores VPS VDS | ProHoster