Cette tâche triviale est survenue un vendredi et aurait dû prendre 2-3 minutes. En gros, comme d'habitude.
Un collègue m'a demandé de corriger un script sur son serveur. Je l'ai fait, je lui ai remis et j'ai lâché par inadvertance : « Le temps s'avance de 5 minutes ». Son serveur, qu'il se débrouille avec la synchronisation. Une demi-heure, une heure a passé, mais il est toujours là, à peiner et à râler silencieusement.
« Imbécile ! » ai-je pensé en passant à la console. de serveurs — Eh bien, je vais encore prendre quelques minutes.
Regardons, ntp, rdate, sdwdate non installés, timesyncd désactivé et non démarré.
# 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
Je noterai tout de suite que l'heure matérielle est correcte : cela facilitera l'orientation par la suite.
C'est de là que sont venues une série d'erreurs.
Première erreur. Arogance.
Clic-clic…
# 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
Tout est parfait, l'heure est synchronisée, le système correspond à l'heure matérielle. « Prends », ai-je laissé échapper et je suis retourné à mes affaires.
« Qu'est-ce que je prends ? s'est indigné le collègue. — L'heure est la même ! »
Plus tu résous de tâches standards, plus ta pensée devient engoncée et tu ne penses pas que la centième ou millième situation pourrait être différente, mais pas cette fois.
# 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
L'heure système est à nouveau incorrecte.
Essayons encore :
# 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
Faisons autrement :
# 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
Et alors comme ça :
# 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
L'heure se règle en une fraction de seconde, et voici qu'elle commence à « avancer » de nouveau.
En même temps, dans les logs, au moment de ce changement manuel, nous ne voyons que des rapports du système, indiquant que l'heure a été modifiée, soit dans le bon, soit dans le mauvais sens, et de temps en temps Resyncing de systemd-timesyncd.
25 août 21:18:51 wisi systemd[1] : L'heure a été changée
25 août 21:18:51 wisi systemd-timesyncd[29258] : L'heure système a changé. Resynchronisation.
25 août 21:18:51 wisi systemd[1187] : L'heure a été changée
25 août 21:18:51 wisi systemd[1] : L'heure a été changée
25 août 21:18:51 wisi systemd[1187] : L'heure a été changée
ici
# ps afx | grep "[1]187"
1187 ? Ss 0:02 /lib/systemd/systemd --user
À ce moment-là, il fallait déjà chercher la cause, mais le cerveau, après 18 ans d'administration, a accumulé des statistiques d'erreurs « d'heure » et, par habitude, blâme encore la synchronisation.
Je la désactive complètement.
# 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
et dans les logs
25 août 21:25:40 wisi systemd[1] : L'heure a été changée
25 août 21:25:40 wisi systemd[1187] : L'heure a été changée
25 août 21:29:30 wisi systemd[1] : L'heure a été changée
25 août 21:29:30 wisi systemd[1187] : L'heure a été changée
Resyncing a disparu et les autres logs sont parfaitement propres.
Vérifions les résultats tcpdump sur le port 123 sur toutes les interfaces. Il n'y a aucune requête, mais l'heure « s'enfuit » toujours.
Deuxième erreur. Précipitation.
Il reste une heure avant la fin de la semaine de travail, et ne pas partir en week-end avec une tâche négligée ennuyeuse ne me tente pas (ne faites pas attention à l'heure dans le code, cet article a été écrit dans les jours suivants).
Et ici encore, au lieu de chercher la cause, j'ai commencé à essayer d'inventer une explication au résultat. Je dis « inventer », parce que, peu importe la logique des explications du résultat, c'est une approche erronée pour résoudre le problème.
Ce serveur est un serveur de streaming et convertit le flux DVB-S2 en IP. Dans le flux DVB-S, il y a des marques temporelles, par conséquent, les récepteurs, les multiplexeurs, les scramblers et les téléviseurs les utilisent souvent pour synchroniser les horloges système. Les pilotes DVB-S des cartes sont compilés dans le noyau, donc le moyen le plus rapide de garantir qu'on élimine le flux DVB-S2 est de débrancher les câbles provenant des « antennes ». Heureusement, le serveur est derrière le mur, donc soit ainsi.
Bien sûr, si dans les logs il y avait ce qu'il devrait y avoir, cela ne se serait pas produit, mais à ce sujet, encore une fois, à la fin de l'article.
Eh bien, puisque nous avons déjà supprimé tous les signaux satellites, supprimons aussi les terrestres — tout en débranchant tous les câbles réseau. Le serveur est coupé du monde extérieur et fonctionne complètement de manière autonome, mais les horloges système continuent d'avancer.
La semaine de travail est terminée, et la question de la date/heure sur lui n'est pas critique, donc je peux simplement rentrer chez moi, mais ici je commets une nouvelle erreur.
Erreur trois. Les conseillers
Jamais ! Ne posez jamais de questions sur des forums et des sites spécialisés (comme stackoverflow), si la réponse nécessite plus que de consulter les résultats de la première page de Google et lire une seule page de man.
On vous renverra vers Google pour lire à nouveau le même man et on vous expliquera les règles du forum/site, mais on ne vous donnera pas de réponse.
Il y a ici des facteurs objectifs :
- personne à part vous ne peut connaître le problème aussi bien ;
- personne ne peut effectuer des tests dans les mêmes conditions que vous.
ainsi que des facteurs subjectifs :
- vous pourriez ne pas fournir tous les éléments nécessaires pour résoudre le problème, parce que vous avez déjà trouvé la « bonne » direction et exposez l'essentiel de la question en vous basant dessus ;
- le responsable (modérateur, ancien membre, admin) a toujours raison, si le responsable a tort… eh bien, vous savez…
Si dans vos réponses vous êtes resté dans le vocabulaire censuré, alors vous avez des nerfs solides.
Solution
Il n'est pas nécessaire de diviser les tâches en simples et complexes.
Cessons de compter sur notre expérience, nos statistiques, nos conseillers et commençons non pas à « expliquer » le résultat final, mais à chercher successivement la cause.
Si quelqu'un fixe l'heure, cela signifie qu'un appel système correspondant doit se produire.
Comme dans la documentation du logiciel, les meilleures documentations sont les sources, de même, en administration système, le meilleur allié est l'audit. auditd.
Un instant de douteJ'ai parcouru les manuels, mais je n'étais pas entièrement sûr que l'heure dans Linux puisse être fixée uniquement par clock_settime et settimeofday, c'est pourquoi pour le premier test, j'ai choisi tous les appels « appropriés » :
# 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
et en excluant s390_runtime_instr, stime, timerfd_create, que auditctl n'a pas reconnu, j'ai initialement lancé l'audit sous la forme :
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 utimesS'étant assuré qu'il n'y avait pas d'autres logs intéressants à part ces deux-là, j'ai ensuite utilisé uniquement eux. syscalls Démarrons l'audit des appels système
et essayons de changer la date : clock_settime et settimeofday Un délai de cinq secondes a été ajouté pour que notre « parasite » corrige l'heure de manière fiable.
# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D
Regardons le rapport :
Ici, nous voyons notre
# 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
et celui qui nous est inconnu date chkcache_proces . Il est apparu dans le rapport ci-dessus, car aureport a trié la sortie par date lors de la conversion depuis un format binaire, et l'événement s'est produit à l'heure que nous avons fixée.date -s «2019-08-22 12:10:00» Qui l'a engendré ?.
— notre parasite a été trouvé. Malgré son comportement « malveillant », il est impossible de renoncer à un système de contrôle d'accès, mais j'aimerais tout de même savoir,
# 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 ?La réponse a été rapidement trouvée dans
Comme c'est mignon ici, :
#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");
}
la ligne commentée du warning Cette tâche triviale est survenue un vendredi.…
Source : habr.com
