Cuanto más sencilla es la tarea, más a menudo cometo errores

Cuanto más sencilla es la tarea, más a menudo cometo errores

Esta tarea trivial surgió un viernes por la tarde y debería haber tomado entre 2 y 3 minutos. En general, como siempre.

Un colega me pidió que arreglara el script en su servidor. Lo hice, se lo entregué y sin darme cuenta solté: “El tiempo es 5 minutos rápido”. Deje que el servidor se encargue de la sincronización. Pasó media hora, una hora y él todavía resoplaba y maldecía en voz baja.

"¡Estúpido! — pensé, cambiando a la consola del servidor — está bien, me tomaré un descanso por un par de minutos más”.

Mira ntp, rdate, sdwdate no instalado sincronización de tiempo deshabilitado y no 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

Aquí notaré inmediatamente que la hora del hardware es correcta: será más fácil navegar más.

Aquí empezó la serie de errores.

El primer error. Auto confianza

Click-clack...

# 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

Todo está bien, la hora está sincronizada, la hora del sistema coincide con la del hardware. “Tómalo”, dije y regresé a mis asuntos.

“¿Tomar qué? - el colega se indignó. "¡Es la misma hora!"

Cuanto más resuelves problemas típicos, más se vuelve tu pensamiento y ya no piensas que la situación centésima o milésima será diferente, pero esta vez no.

# 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

La hora del sistema vuelve a ser incorrecta.

Intentemoslo de nuevo:

# 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

Hagámoslo 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

Y entonces:

# 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

El tiempo se fija en una fracción de segundo e inmediatamente comienza a "correr" nuevamente.

Al mismo tiempo, en los registros, en el momento de dicho cambio manual, solo vemos informes del sistema de que la hora ha cambiado, respectivamente, en la dirección correcta/incorrecta y ocasionalmente Resincronizando desde 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

aquí

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

A estas alturas ya era necesario buscar el motivo, pero a lo largo de 18 años de administración, el cerebro ha acumulado estadísticas sobre errores de “tiempo” y, por costumbre, vuelve a culpar a la sincronización.
Apaguémoslo por completo.

# 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

y en los 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

Resincronizando desapareció y, por lo demás, los registros están impecables.

Comprobando las conclusiones tcpdump en el puerto 123 en todas las interfaces. No hay solicitudes, pero el tiempo todavía se acaba.

Error dos. Correr

Queda una hora para el final de la semana laboral y no quiero irme el fin de semana con un problema trivial sin resolver (no prestes atención a la hora en el código, el artículo se escribió en los días siguientes ).
Y aquí nuevamente, en lugar de buscar la razón, comencé a intentar encontrar una explicación para el resultado. Digo "inventar" porque no importa cuán lógica pueda ser la explicación del resultado, es un enfoque defectuoso para resolver el problema.

Este servidor es un servidor de transmisión y convierte la transmisión DVB-S2 en IP. La transmisión DVB-S contiene marcas de tiempo, por lo que los receptores, multiplexores, codificadores y televisores suelen utilizarlas para sincronizar el reloj del sistema. Los controladores de la placa DVB-S están integrados en el núcleo, por lo que la forma más rápida de garantizar que se elimine la transmisión DVB-S2 es desconectar los cables que vienen de las "placas". Afortunadamente, el servidor está detrás de la pared, que así sea.

Por supuesto, si los registros hubieran contenido lo que debería estar allí, esto no habría sucedido, pero hablaremos más sobre eso al final del artículo.

Bueno, como ya hemos eliminado todas las señales de satélite, también eliminaremos las terrestres; al mismo tiempo, desconectaremos todos los cables de red. El servidor queda aislado del mundo exterior y funciona de forma completamente autónoma, pero el reloj del sistema todavía tiene prisa.

La semana laboral terminó y el tema de fecha/hora en sí no es crítico, así que puedes irte a casa, pero aquí cometo un nuevo error.

Error tres. Asesores

¡Nunca! Nunca haga preguntas en foros y sitios especializados en general (a la stackoverflow) si la respuesta requiere más que estudiar la primera página de Google y leer una página de manual.

Te enviarán de regreso a Google, leerán al mismo hombre y te explicarán popularmente las reglas del foro/sitio, pero no te darán una respuesta.

Aquí hay algunos factores objetivos:

  • nadie, excepto usted, puede conocer el problema también;
  • nadie puede realizar pruebas en las mismas condiciones que las tuyas

y subjetivo:

  • es posible que no dé toda la información para resolver el problema, porque ya ha encontrado la dirección “correcta” y está presentando la esencia del problema enfocándose en ella;
  • el capataz (moderador, veterano, administrador) siempre tiene razón, si el capataz se equivoca... bueno, ya sabes...

Si al responder a los comentarios te mantuviste dentro de los límites del vocabulario censurado, entonces tienes los nervios fuertes.

Solución

No es necesario dividir las tareas en simples y complejas.

Dejamos de confiar en nuestra experiencia, estadísticas, asesores y comenzamos a no "explicar" el resultado final, sino a buscar constantemente la razón.

Dado que alguien establece la hora, debe realizarse la llamada al sistema correspondiente.

Así como en la documentación de software los mejores documentos son las fuentes, en la administración de sistemas el mejor asistente es la auditoría, en nuestro caso auditar.

Un momento de dudaRevisé el maná, pero no estaba del todo seguro de que la hora en Linux solo se pueda configurar hora_fijada del reloj и establecer la hora del día, así que para la primera prueba elegí todas las llamadas "adecuadas":

# 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

y descartando s390_runtime_instr, stime, timerfd_createcual auditoríactl no lo reconoció, inicialmente lanzó una auditoría en la forma:

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

Después de asegurarme de que no hay otros registros en las ubicaciones de registros que me interesan llamadas al sistema Además de estos dos, solo los usé más.

Ejecución de una auditoría de llamadas al sistema hora_fijada del reloj и establecer la hora del día e intenta cambiar la fecha:

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

Se añade un retraso de cinco segundos para que nuestro “parásito” tenga la garantía de corregir la hora.

Nos fijamos en el informe:

# 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

Aquí vemos nuestro datos y desconocido para nosotros procesos_chkcache. Terminó en el informe anterior porque aureport clasificó la salida por fecha al convertir de binario, y el evento ocurrió en el momento que configuramos fecha -s "2019-08-22 12:10:00".
¿Quién lo dio a luz?

# 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 - Nuestro parásito ha sido encontrado. A pesar de su comportamiento “malicioso”, es imposible rechazar el sistema de acceso condicional, pero aún así me gustaría saber oscam¿Qué carajo?

La respuesta se encuentra rápidamente en códigos fuente:

#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 lindo se ve aqui Comentado línea advertencia...

Fuente: habr.com

Añadir un comentario