En résumé: La commande ‹ dmesg -T › affiche les principaux événements système avec une date ‹ lisible par un humain › (human-readable time), qui peut être trompeuse.
En effet, cet affichage est sujet à interprétation, parce qu’il ne représente pas la date et l’heure qu’il était au moment de l’événement, mais plutôt la date correspondant au temps écoulé depuis cet événement et la date actuellement affichée par votre RPI.
Voici un exemple:
Je branche une clé USB sur mon RPI à 23:02:00 (heure de ma machine): la commande dmesg -T m’affiche que cet événement s’est produit à 23h02.
Quelques minutes plus tard, je change l’heure de ma machine (disons que je la retarde d’une heure). La commande ‹ dmesg -T › me dit que la clé a été branchée à 22h02.
Cependant, si j’affiche cet événement avec ‹ dmesg ›, le temps systeme de ce même événement porte toujours le même horodatage, avant ou après le changement d’heure système.
Quelques infos complémentaires:
Vous ne verrez pas ce comportement sur une machine équipée d’une horloge temps réel matérielle (Real-Time Clock chip), ou synchronisée en NTP (je n’ai pas rajouté de RTC sur ma RPI, et j’ai arrêté NTP pour faire les tests). Ce comportement n’est a priori pas spécifique à la RPI: il y a toutes les chances que toute machine linux dans les mêmes conditions (ni RTC, ni NTP) montre le même comportement.
Je me suis intéressé à ce comportement lors de l’introduction de la leap second (voir un sujet que j’ai posté précédemment). La commande ‹ dmesg -T › prétendait que l’introduction de la leap second avait eu lieu à 23:59:58, et non à 23:59:59 comme je m’y attendais ( lors de l’introduction d’une leap second, l’affichage de l’heure UTC doit montrer successivement: 23:59:58 23:59:59 23:59:60 00:00:00). Comme l’introduction de la leap second revient pour le système à retarder sa date système d’une seconde, les événements antérieurs sont datés d’une seconde de plus dans le passé. En tenant compte de la leap seconde dans la reconstitution de la chronologie des secondes écoulées entre un événement daté du 1er janvier et l’événement d’introduction de la leap seconde, à partir des temps systèmes affichés par ‹ dmesg › (sans l’option), on retombe sur un événement d’introduction à 23:59:59 .
Je joins quelques traces de mes tests si vous voulez refaire les manips.
Time is synchronized with ntp through the net:
mercredi 4 janvier 2017, 23:06:01 (UTC+0100)
ifconfig wlan0
:
wlan0 Link encap:Ethernet HWaddr b8:27:eb:32:0f:ec
inet adr:192.168.1.16 Bcast:192.168.1.255 Masque:255.255.255.0
adr inet6: fe80::f61:1bb3:79a5:3e2c/64 Scope:Lien
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:631769 errors:0 dropped:453408 overruns:0 frame:0
TX packets:15282 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 lg file transmission:1000
RX bytes:145651532 (138.9 MiB) TX bytes:1365398 (1.3 MiB)
:~ service ntp status
â— ntp.service - LSB: Start NTP daemon
Loaded: loaded (/etc/init.d/ntp)
Active: active (running) since mer. 2017-01-04 23:11:21 CET; 1min 40s ago
Process: 12509 ExecStop=/etc/init.d/ntp stop (code=exited, status=0/SUCCESS)
Process: 12545 ExecStart=/etc/init.d/ntp start (code=exited, status=0/SUCCESS)
CGroup: /system.slice/ntp.service
└─12554 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 106:111
stop ntp, then set time back by one hour
:~ sudo service ntp stop
now, system time is cpu-clock driven.
take time reference in system messages.
:~ dmesg | tail -2
[386664.098103] sdb: sdb1
[386664.106524] sd 5:0:0:0: [sdb] Attached SCSI removable disk
same, with human readable time.
:~ dmesg -T | tail -2
[mer. janv. 4 23:02:29 2017] sdb: sdb1
[mer. janv. 4 23:02:29 2017] sd 5:0:0:0: [sdb] Attached SCSI removable disk
set clock back by one hour::~ sudo date --set 22:23:00
mercredi 4 janvier 2017, 22:23:00 (UTC+0100)
display date and time
mercredi 4 janvier 2017, 22:24:51 (UTC+0100)
redo dmesg commands without -T option:
[386664.098103] sdb: sdb1
[386664.106524] sd 5:0:0:0: [sdb] Attached SCSI removable disk
the time tag has not changed
now, dmesg -T:
[mer. janv. 4 22:01:06 2017] sdb: sdb1
[mer. janv. 4 22:01:06 2017] sd 5:0:0:0: [sdb] Attached SCSI removable disk
restore ntp service and wait for the time to be resynch’d; the redo the dmesg commands, to see the time tags reinterpreted.
:~ sudo service ntp start
after some ten seconds, system time get resynchronized.
what time is it?
mercredi 4 janvier 2017, 23:36:40 (UTC+0100)
redo the dmesg commands to see the human-readable timestamps are correct again.
[386664.098103] sdb: sdb1
[386664.106524] sd 5:0:0:0: [sdb] Attached SCSI removable disk
[mer. janv. 4 23:02:29 2017] sdb: sdb1
[mer. janv. 4 23:02:29 2017] sd 5:0:0:0: [sdb] Attached SCSI removable disk
