Twitter iPhone pliant OnePlus 11 PS5 Disney+ Orange Livebox Windows 11

Bug étrange NTP

18 réponses
Avatar
François Boisson
Bonjour à tous

J'ai chez moi depuis plus de six ans un serveur NTP (qui est d'ailleurs dans
le pool NTP). Ce serveur marche fort bien mais a un bug bizarre depuis le
passage à squeeze (sans certitude, je ne me souviens pas de ce bug au début
mais bon). Les faits:

Toutes les 2^22 secondes soit en gros 1 mois 20 jours, le serveur, prend
89,06s d'avance (et est ejecté du pool donc). Les bugs se
sont produit à ces dates (et peut être avant):
12/08/2014 13:44:02
30/09/2014 02:56:06 17/11/2014 15:02:38 05/01/2015 04:14:12
22/02/2015 17:21:55
12/04/2015 07:30:46
30/05/2015 20:40:21

Le serveur est un stratum 2 et ça n'est pas du semble-t-il à une dérive du
serveur de stratum 1 (un décalage à ce point n'est de toute façon pas
possible). Le noyau est un 2.6.32-5-686 et la ntp est 1:4.2.6.p2+dfsg-1+deb6u3

Sur un autre serveur ntp, lui aussi dans le pool, lui aussi squeeze, avec la
même version de ntp mais le noyau de lenny 2.6.26-2-686, il n'y a pas ce bug.

Je pense plutôt à un souci matériel, j'ai le souvenir d'un plantage du module
rtc de temps à autre avant de changer de noyau. La machine a été reboutée aux
dates suivantes
francois@cerbere:/var/log$ ls -altr dmesg*
-rw-r----- 1 root adm 6847 17 avril 2012 dmesg.4.gz
-rw-r----- 1 root adm 6456 20 mai 2013 dmesg.3.gz
-rw-r----- 1 root adm 6494 19 déc. 2013 dmesg.2.gz
-rw-r----- 1 root adm 7935 7 févr. 2014 dmesg.1.gz
-rw-r----- 1 root adm 22567 10 avril 2014 dmesg.0
-rw-r----- 1 root adm 23616 7 mai 2014 dmesg
le passage en squeeze ayant été fait le 7 février 2014.

C'est un FitPC installé en 2008 qui marche de façon continuelle (là son uptime
est de 11:42:58 up 437 days, 3 min

Le bug en lui même ne me gêne pas, je vais faire un «at» régulier qui
relancera le démon ntp tous les 2^22 secondes mais j'aimerais avoir une
explication notamment savoir pourquoi 89,06s.

Si quelqu'un a une idée.


François Boisson

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers debian-user-french-REQUEST@lists.debian.org
En cas de soucis, contactez EN ANGLAIS listmaster@lists.debian.org
Archive: https://lists.debian.org/20150718114851.99eaf637493362ddc9b84842@maison.homelinux.net

10 réponses

1 2
Avatar
François Boisson
[precisions]
Toutes les 2^22 secondes soit en gros 1 mois 20 jours, le serveur, prend
89,06s d'avance (et est ejecté du pool donc). Les bugs se
sont produit à ces dates (et peut être avant):
12/08/2014 13:44:02
30/09/2014 02:56:06 17/11/2014 15:02:38 05/01/2015 04:14:12
22/02/2015 17:21:55
12/04/2015 07:30:46
30/05/2015 20:40:21



et bien évidement aujourd'hui: 18/07/2015 09:48:24

[...]

Je pense plutôt à un souci matériel,



Cela d'autant plus qu'en vérifiant le .bash_history de root, je sais que le
serveur ntp a été démarré pendant la période août 2014 et aujourd'hui ce qui
signifie que la période de 2^22 secondes ne vient pas du serveur NTP mais du
noyau et de la machine.

Cette période de 2^22 et le délai de 86,06s disent ils quelque chose à
quelqu'un?

François Boisson

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
Bernard Schoenacker
Le Sat, 18 Jul 2015 14:28:46 +0200,
François Boisson a écrit :

[precisions]
> Toutes les 2^22 secondes soit en gros 1 mois 20 jours, le serveur,
> prend 89,06s d'avance (et est ejecté du pool donc). Les bugs se
> sont produit à ces dates (et peut être avant):
> 12/08/2014 13:44:02
> 30/09/2014 02:56:06 17/11/2014 15:02:38 05/01/2015 04:14:12
> 22/02/2015 17:21:55
> 12/04/2015 07:30:46
> 30/05/2015 20:40:21

et bien évidement aujourd'hui: 18/07/2015 09:48:24

[...]
>
> Je pense plutôt à un souci matériel,

Cela d'autant plus qu'en vérifiant le .bash_history de root, je sais
que le serveur ntp a été démarré pendant la période août 2014 et
aujourd'hui ce qui signifie que la période de 2^22 secondes ne vient
pas du serveur NTP mais du noyau et de la machine.

Cette période de 2^22 et le délai de 86,06s disent ils quelque chose à
quelqu'un?

François Boisson





bonjour,

serait il possible de voir du côté de adjtimex ?

slt
bernard

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
François Boisson
Le Sat, 18 Jul 2015 14:37:54 +0200
Bernard Schoenacker a écrit:

bonjour,

serait il possible de voir du côté de adjtimex ?



Plus précisemment? Voilà ce que donne un dump de adjtimex:

:~$ ./adjtimex
code retour: 0
modes : 0
offset (time offset ns ou us) : 344
freq (freq offset 2^-16 ppm) : 6405368
maxerror (max error us) : 566662
esterror (estimated error us) : 314
status : 16385
constant (PLL) : 10
precision (precision us) : 1
tolerance (ppm) 32768000
Current time : 18/07/2015 15:25:49.357325
tick (Microseconds between clock ticks) : 10000
ppsfreq (puls per second 2^-16 ppm) : 0
jitter (PPS jitter ns ou us) : 0
shift (s, RO) : 0
stabil (stability 2^-16 ppm) : 0
jitcnt (PPS jitter limit exceeded, RO) : 0
calcnt (PPS calcilbration interval, RO) : 0
errcnt (PPS calibration count, RO) : 0
stbcnt (PPS stability limit exceeded, RO) : 0
tai (TAI offset) : 1


François Boisson

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
Yves Rutschle
On Sat, Jul 18, 2015 at 02:28:46PM +0200, François Boisson wrote:
Cette période de 2^22 et le délai de 86,06s disent ils quelque chose à
quelqu'un?



Pas spécifiquement, mais la description me rappelle un très
vieux bug que j'avais eu, où l'on ne masquait pas les
interruptions dans le traitement de l'interruption timer, et
du coup "de temps en temps", on revenait une 60e de secondes
en arrières, ce qui correspondait à 2^32 interruptions du
timer (ou 2^32 jiffies, je sais plus), dûe à un compteur qui
du coup ne gérait plus une retenue correctement (désolé de
l'imprécision, c'était il y a 15 ans...).

Du coup, peut-être tu as un compteur de 22 bits qui déborde
mal quelque part et les 86s correspondent à 2^x d'une
certaine fréquence?

C'est beau, l'informatique :-)

Y.

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
Vincent Lefevre
On 2015-07-18 14:28:46 +0200, François Boisson wrote:
[precisions]
> Toutes les 2^22 secondes soit en gros 1 mois 20 jours, le serveur, prend
> 89,06s d'avance (et est ejecté du pool donc). Les bugs se
> sont produit à ces dates (et peut être avant):
> 12/08/2014 13:44:02
> 30/09/2014 02:56:06 17/11/2014 15:02:38 05/01/2015 04:14:12
> 22/02/2015 17:21:55
> 12/04/2015 07:30:46
> 30/05/2015 20:40:21

et bien évidement aujourd'hui: 18/07/2015 09:48:24

[...]
>
> Je pense plutôt à un souci matériel,

Cela d'autant plus qu'en vérifiant le .bash_history de root, je sais que le
serveur ntp a été démarré pendant la période août 2014 et aujourd'hui ce qui
signifie que la période de 2^22 secondes ne vient pas du serveur NTP mais du
noyau et de la machine.

Cette période de 2^22 et le délai de 86,06s disent ils quelque chose à
quelqu'un?



Il y a un autre bug: c'était 89,06s dans ton premier message, et c'est
maintenant 86,06s!

Essaie de faire une recherche sur Google avec ces valeurs sous
diverses écritures. Mais j'ai l'impression que tu est le seul à avoir
ce problème, sinon il aurait été détecté, ce qui tendrait à indiquer
un problème matériel. Moi, c'était quand j'avais un Atari et un Mac
côte à côte il y a 25 ans environ: quand j'allumais mon Mac, l'Atari
passait subitement au 14 janvier 2028.

Pour le 2^22, je ne vois pas, à part le fait que 10^22 est la plus
grande puissance de 10 tenant exactement dans un double. Mais ça
m'étonnerait qu'il y ait un lien. Ou alors un compteur sur 32 bits
incrémenté toutes les 1/1024 secondes?

Pour le décalage, c'est peut-être un terme d'erreur dans un calcul
de date.

Il faudrait logger le contenu de l'horloge matérielle (RTC) et de
l'horloge système juste un peu avant que le bug se produise et un
peu après.

--
Vincent Lefèvre - Web: <https://www.vinc17.net/&gt;
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/&gt;
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
Philippe Gras
Le 19 juil. 2015 à 17:54, Vincent Lefevre a écrit :

On 2015-07-18 14:28:46 +0200, François Boisson wrote:

Essaie de faire une recherche sur Google avec ces valeurs sous
diverses écritures. Mais j'ai l'impression que tu est le seul à avoir
ce problème, sinon il aurait été détecté, ce qui tendrait à indiquer
un problème matériel. Moi, c'était quand j'avais un Atari et un Mac
côte à côte il y a 25 ans environ: quand j'allumais mon Mac, l'Atari
passait subitement au 14 janvier 2028.



Logique : Atari, c'est l'avenir ;-)

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists" target="_blank" class="text-blue hover:opacity-90 " style="word-break: break-all;" rel="noopener nofollow">http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/" target="_blank" class="text-blue hover:opacity-90 " style="word-break: break-all;" rel="noopener nofollow">https://lists.debian.org/




--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists" target="_blank" class="text-blue hover:opacity-90 " style="word-break: break-all;" rel="noopener nofollow">http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/" target="_blank" class="text-blue hover:opacity-90 " style="word-break: break-all;" rel="noopener nofollow">https://lists.debian.org/
Avatar
François Boisson
Le Sun, 19 Jul 2015 12:50:16 +0200
Yves Rutschle a écrit:

On Sat, Jul 18, 2015 at 02:28:46PM +0200, François Boisson wrote:
> Cette période de 2^22 et le délai de 86,06s disent ils quelque chose à
> quelqu'un?

Pas spécifiquement, mais la description me rappelle un très
vieux bug que j'avais eu, où l'on ne masquait pas les
interruptions dans le traitement de l'interruption timer, et
du coup "de temps en temps", on revenait une 60e de secondes
en arrières, ce qui correspondait à 2^32 interruptions du
timer (ou 2^32 jiffies, je sais plus), dûe à un compteur qui
du coup ne gérait plus une retenue correctement (désolé de
l'imprécision, c'était il y a 15 ans...).

Du coup, peut-être tu as un compteur de 22 bits qui déborde
mal quelque part et les 86s correspondent à 2^x d'une
certaine fréquence?



Je vais faire plusieurs tests:
* J'ai redémarré le serveur hier. Si le bug est lié au serveur NTP, le
prochain aura lieu le Dimanche 6/09 au matin et non le 4/09
* Je vais regarder si il y a une dérive de l'horloge RTC, je me demande si
ces 89,06s ne viendrait pas de là (mais théoriquement l'horloge RTC est mise
à jour toutes les 11 minutes)

À suivre....

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
Yves Rutschle
On Mon, Jul 20, 2015 at 07:27:35AM +0200, François Boisson wrote:
* Je vais regarder si il y a une dérive de l'horloge RTC, je me demande si
ces 89,06s ne viendrait pas de là (mais théoriquement l'horloge RTC est mise
à jour toutes les 11 minutes)



Pour autant qu'il m'en souvienne, l'horloge RTC n'est lue
qu'une fois au démarrage puis plus jamais, du coup sa dérive
(probable) ne devrait rien affecter sur un système en
fonctionnement.

Y.

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
François Boisson
Le Sun, 19 Jul 2015 17:54:21 +0200
Vincent Lefevre a écrit:

Il y a un autre bug: c'était 89,06s dans ton premier message, et c'est
maintenant 86,06s!




Celui là je le connais bien, c'est l'interface clavier chaise. Lire 89,06s.

[...]

Pour le 2^22, je ne vois pas, à part le fait que 10^22 est la plus
grande puissance de 10 tenant exactement dans un double. Mais ça
m'étonnerait qu'il y ait un lien. Ou alors un compteur sur 32 bits
incrémenté toutes les 1/1024 secondes?



C'est ce que je pense avec un souci du type de ce qu'à suggéré Yves, mais je
ne trouve rien dans les sources.


Il faudrait logger le contenu de l'horloge matérielle (RTC) et de
l'horloge système juste un peu avant que le bug se produise et un
peu après.




L'heure matérielle est censée se mettre à jour toutes les 11 minutes. En fait
tout ce passe comme si la machine s'était gelée pendant ces 89,06s. On
pourrait peut être imaginer que pour une raison ou une autre, aucune
interruption n'ait été traitée pendant ce laps de temps. Maids ça me parait
tiré par les cheveux. La machine est un FitPC cadencé à 499.955MHz


François Boisson

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
Avatar
François Boisson
Le Mon, 20 Jul 2015 10:08:07 +0200
François Boisson a écrit:

L'heure matérielle est censée se mettre à jour toutes les 11 minutes. En fait
tout ce passe comme si la machine s'était gelée pendant ces 89,06s. On
pourrait peut être imaginer que pour une raison ou une autre, aucune
interruption n'ait été traitée pendant ce laps de temps. Maids ça me parait
tiré par les cheveux. La machine est un FitPC cadencé à 499.955MHz



Autre chose qui m'incite à penser à des interruptions non traitées:
Voilà un partie du fichier de log (j'"ai une manie, je je fais des logs de
tout):
Dans l'ordre, Jour, Mois, Heure, Minutes, Seconde, Decalage avec
un autre serveur NTP, temps en secondes depuis le début de la journée
et enfin temps écoulé depuis la ligne suivante.

18 Jul 9 32 24 -0,001192 34344 317
18 Jul 9 37 41 -0,001053 34661 325
18 Jul 9 43 6 -0,000326 34986 318
18 Jul 9 48 24 89,060533 35304 314
18 Jul 9 53 38 89,06075 35618 314
18 Jul 9 58 52 89,060771 35932 318
18 Jul 10 4 10 89,061083 36250 314
18 Jul 10 9 24 89,060588 36564 315
18 Jul 10 14 39 89,060753 36879 403
18 Jul 10 21 22 -0,000297 37282 314
18 Jul 10 26 36 -0,000587 37596 314

On voit bien le souci à 09:48:24, on voit bien que malgré le décalage
de leur système, le temps écoulé entre deux enregistrements restde de l'ordre
de 325s. On voit également que lorsque j'ai remis la machine à l'heure,
il y a un décalage de l'ordre de 89s (403 - 89 = 314). Le script est un
while /bin/true; do
betises diverses
sleep 300
done

sleep appelle xnanosleep qui appelle nanosleep. La norme POSIX indique que

«Configurer la valeur de l'horloge CLOCK_REALTIME avec clock_settime() ne
doit pas avoir d'effet sur les threads bloqués attendant un service de temps
relatif basé sur cette horloge. Cela inclut la fonction nanosleep() ;
En conséquence, ces services de temps doivent expirer lorsque la durée
relative demandée est atteinte, indépendamment de l'ancienne ou
la nouvelle valeur de l'horloge. »

En clair donc, il y eu pour la machine 314s d'interruption horloge entre chaque
ligne, changement d'heure ou pas. Lorsque j'ai changé d'heure, lui faisant rattraper
les 89,06s perdus, on retrouve ces 89,06s dans l'expression du temps écoulé entre deux
mesures (314s vraies + 89s de décalage du à ma remise à l'heure). Par contre, lors
du bug, il n'y a pas de décalage dans le temps écoulé, on aurait du avoir
314-89"5 [À ce stade, je félicite les 5 qui sont encore en train de lire!]. Bref
tout ça pour dire qu'on dirait bien que la machine s'est figée 89s ou que c'est
tout comme. Vraiment mystérieux ce truc.

François Boisson

--
Lisez la FAQ de la liste avant de poser une question :
http://wiki.debian.org/fr/FrenchLists

Pour vous DESABONNER, envoyez un message avec comme objet "unsubscribe"
vers
En cas de soucis, contactez EN ANGLAIS
Archive: https://lists.debian.org/
1 2