Seltsames im Skript angestossen über udev-Regel

[halo44]

Auf meinem QNAP-NAS läuft seit Jahren eine Debian-Installation aktuell mit Buster (letzte für QNAP unterstützte).

Ich führe ein neues Skript über udev-Regel aus, wenn ich einen bestimmten USB-Stick anschließe. Der Stick wird auch erkannt und das Skript auch ausgeführt.

Im Skript nutze ich u.a. touch und date aus dem Paket coreutils. Führe ich touch für eine neu zu erstellende Datei aus, so erhält sie als Erstellungsdatum den 14.02.19. Führe ich date +%d > heute aus, so enthält "heute" 14 und nicht 16 (heute ist der 16.09.21).

Führe ich die Befehle nicht über das Skript aus der udev-Regel sondern im Terminal aus, so sind die Ergebnisse richtig: 16.09.21 und 16.

Ich habe inzwischen die Aufgabe, die das Skript erledigen sollte, anderweitig gelöst. Trotzdem würde ich gerne wissen, was hier falsch läuft.

Hat jemand eine Idee oder Anregung? Hierfür danke.

Gruss H.

[minuseins]

Die einfachste Lösung ist wahrscheinlich, dass auf deinem QNAS das Datum falsch eingestellt ist und glaubt tatsächlich 2 Tage in der Vergangenheit zu sein.

Code: Alles auswählen

date

Gibt dir das aktuell eingestellte Datum zurück.

Wenn hier der 14. September 2021 zurückkommt, dann solltest du das Problem relativ einfach mit einem:

Code: Alles auswählen

sudo ntpdate-debian

beheben können. Einfach danach mit dem "date" Befehl anschießend überprüfen ob Uhrzeit und Datum dann korrigiert worden sind.

p.s.

Wer genau lesen kann ist klar im Vorteil... guck doch mal ob es Unterschiede gibt bei der Ausgabe der folgenden Befehle gibt:

Code: Alles auswählen

timedatectl
hwclock -r

gibt. Also abhängig davon ob über Terminal oder per UDEV-Rule ausgeführt.

[halo44]

Die einfachste Lösung ist wahrscheinlich, dass auf deinem QNAS das Datum falsch eingestellt ist und glaubt tatsächlich 2 Tage in der Vergangenheit zu sein ...

Nein, das Datum ist richtig eingestellt, wie sich ja darin zeigt, dass date im Terminal das richtige Datum zeigt.

Auch zeigt sich heute am 17.09.21 in date +%d der Tag 14, also 3 Tage zurück.

Da auch das Datum beim touch heute wieder den 14.02.19 zeigt, vermute ich dass vielleicht das Paket coreutils für die Architektur armel in Buster vom 14.02.19 stammt. Eine Begründung kann ich mangels tiefer gehenden Wissens nicht liefern.

Gruss H.

[minuseins]

Und was ist die Ausgabe der anderen beiden Befehle? Also "hwclock -r" und "timedatectl"?

Gibt es da auch Unterschiede?

[halo44]

hwclock -r zeigt im Skript, welches über die udev-Regel angestossen wird, das richtige Datum. Auch im Terminal zeigt es dieses Datum.

timedatectl zeigt in o.a. Skript keine Ausgabe. Auf stderr wird ausgegeben "Failed to create bus connection: No such file or directory". Im Terminal zeigt es das richtige Datum.

Gruss H.

[reox]

Auch zeigt sich heute am 17.09.21 in date +%d der Tag 14, also 3 Tage zurück.

Wie? Also so:

Code: Alles auswählen

$ date
Sun 19 Sep 2021 11:34:39 AM CEST
$ date +%d
14

was sagt

Code: Alles auswählen

$ LANG=C date +%d

?

In jedem Fall klingt das eher nach Bugreport schreiben...

[halo44]

Im Eingangspost ist eigentlich bereits alles gesagt. Wie dort schon ausgeführt, wird auf dem NAS ein Skript über udev-Regel angestossen. In diesem Skript führe ich aus

Code: Alles auswählen

date +%d > heute

Der Inhalt von heute ist 14

Code: Alles auswählen

date > heute

Der Inhalt von heute ist jetzt Thu Feb 14 11:12:08 CET 2019

Öffne ich über ssh auf dem NAS ein Terminal und führe die Befehle im Terminal aus erhalte ich die richtigen Werte vom heutigen Tage.

Auch

Code: Alles auswählen

LANG=C date +%d

zeigt das gleiche Verhalten.

Gruss H.

[reox]

Weil du schriebst, dass im Terminal die richtige Uhrzeit angezeigt wird, ich dachte du hast das auch mit date angesehen.
Und date ist bei dir auch das richtige executable?

edit: Was ich mir jetzt auch noch gedachte habe: date holt ja die zeit per time.h und da gibts teilweise solche berichte: https://stackoverflow.com/questions/344 ... 35959-1969
Offenbar bekommst du ja auch immer die selbe Zeit zurückgeliefert.
Vermutlich holen sich Tools auf der commandline die zeit woanders her, zB von systemd.
Evt hast du da ein ähnliches Problem.

[Tintom]

Wie sieht denn die udev-Regel aus? Und wie das Skript, das aufgerufen wird?
Vielleicht änderst du einmal testweise den Aufruf des Skripts in RUN+="/bin/bash -c '/bin/date > /tmp/datum'", damit du auch sicher sein kannst, dass dein Skript nicht durch falsche Binaries oder relative Pfade gestört wird.

[uname]

hwclock -r zeigt im Skript, welches über die udev-Regel angestossen wird, das richtige Datum. Auch im Terminal zeigt es dieses Datum.

Kannst du den Befehl nicht nutzen?

Z. B. so:

Code: Alles auswählen

hwclock -r|awk {'print $2'}

Im Script solltest du im übrigen überall vollständige Pfade nutzen wie z. B. /bin/date (coreutils) oder /sbin/hwclock (util-linux).

[halo44]

Danke für Eure Antworten. Ich werde die Fragen jeweils in eigenen Beiträgen beantworten, weil ich für alle Änderungen das NAS neu starten und mich per per ssh aufschalten muss. Das dauert. Später werde ich noch über weitere Merkwürdigkeiten das mysteriöse Datum 14.02.2019 betreffend berichten.

Zunächst zu @Tintom. Die udev-Regel lautet

Code: Alles auswählen

SUBSYSTEM=="block", ACTION=="add", ENV{ID_MODEL}=="Flash_Disk", ENV{ID_VENDOR}=="Generic", ENV{ID_SERIAL_SHORT}=="66F8C741", SYMLINK+="usbstick", RUN+="/bin/sh /usr/local/bin/unlock-luks-0"

Die beiden ersten Befehle des Skripts /usr/local/bin/unlock-luks-0

Code: Alles auswählen

#!/bin/bash
/bin/date +%d > /home/hanswerner/heute
/bin/date > /home/hanswerner/heute-lang
......

Die Datei heute zeigt jetzt 14, die Datei heute-lang zeigt Thu Feb 14 11:12:08 CET 2019.

Den Aufruf für RUN+ werde ich später mal durchführen, nach Änderung und Neustart des NAS.

Gruss H.

[halo44]

hwclock -r zeigt im Skript, welches über die udev-Regel angestossen wird, das richtige Datum. Auch im Terminal zeigt es dieses Datum.

Kannst du den Befehl nicht nutzen?

Z. B. so:

Code: Alles auswählen

hwclock -r|awk {'print $2'}

Im Script solltest du im übrigen überall vollständige Pfade nutzen wie z. B. /bin/date (coreutils) oder /sbin/hwclock (util-linux).

Natürlich könnte ich auch diesen Befehl nutzen. Deswegen aber darf date keine falschen Ergebnisse liefern.

Vollständige Pfade nutze ich (siehe vorherigen Post mit Inhalt der udev-Regel und Skript).

Gruss H.

[halo44]

... Was ich mir jetzt auch noch gedachte habe: date holt ja die zeit per time.h und da gibts teilweise solche berichte: https://stackoverflow.com/questions/344 ... 35959-1969 ...

Das ist tatsächlich ein hochinteressanter Link. Werde die dort geposteten Lösungen später mal durchprobieren.

Im Eröffnungsbeitrag habe ich ja schon erwähnt, dass nicht nur date im Skript den 14.02.2019 zeigt sondern auch mit touch erstellte Dateien das gleiche falsche Datum zeigen.

Inzwischen habe ich weitere Merkwürdigkeiten ohne Bezug zur udev-Regel festgestellt. Diese zeigen sich im Terminal.

Prüfe ich die Datenpartitionen auf dem NAS auf mount- und prüf-Vorgänge, so zeigen alle Partitionen ebenfalls das Datum 14.02.2019, allerdings mit unterschiedlichen Uhrzeiten.

Code: Alles auswählen

root@NAS-01:~# tune2fs -l /dev/sda8 | egrep -i "Last"
Last mounted on:          /Daten-Filme
Last mount time:          Thu Feb 14 11:12:37 2019
Last write time:          Thu Feb 14 11:12:37 2019
Last checked:             Thu Feb 14 11:12:25 2019
root@NAS-01:~# tune2fs -l /dev/sda6 | egrep -i "Last"
Last mounted on:          /Daten-2
Last mount time:          Thu Feb 14 11:12:10 2019
Last write time:          Thu Feb 14 11:12:10 2019
Last checked:             Thu Feb 14 11:12:07 2019
root@NAS-01:~# tune2fs -l /dev/sda5 | egrep -i "Last"
Last mounted on:          /Daten-1
Last mount time:          Thu Feb 14 11:12:24 2019
Last write time:          Thu Feb 14 11:12:24 2019
Last checked:             Thu Feb 14 11:12:10 2019

Irgendwas scheint am 14.02.2019 geschehen sein, was nicht mehr nachvollziehbar ist.

Gruss H.

[uname]

Du könntest mal mit strace die wirklich große Keule rausholen.

Code: Alles auswählen

/usr/bin/strace -ff -o out.txt /bin/date

Auf der Kommandozeile:

Code: Alles auswählen

/usr/bin/strace -ff -o terminal.txt /bin/date

Datei lautet dann irgendwie terminal.txt.<prozessid>

Im Script:

Code: Alles auswählen

#!/bin/bash
/bin/date +%d > /home/hanswerner/heute
/bin/date > /home/hanswerner/heute-lang
/usr/bin/strace -ff -o script.txt /bin/date
......

Datei lautet dann irgendwie script.txt.<prozessid>

Gibt es Unterschiede?

Code: Alles auswählen

zdump /etc/localtime

Kannst du dir in dem Zusammenhang gleich mitanschauen, welches ich nin meiner Terminal-Version gefunden habe.

[Tintom]

Weiter oben hat schon jemand geschrieben: Kannst du bitte einmal die Ausgabe von timedatectl (aus dem Terminal, nicht durch udev-Skript) posten?

[halo44]

Also die Dateien sind an einigen Stellen unterschiedlich, allerdings zeigt sich wohl der entscheidende Unterschied in der 5.Zeile vor dem Ende der Datei.

In der Terminal-Ausgabe:

write(1, "Mo 20. Sep 15:53:00 CEST 2021\n", 30) = 30

In der Skript-Ausgabe:

write(1, "Thu Feb 14 11:12:09 CET 2019\n", 29) = 29

Wird die komplette Ausgabe trotzdem noch benötigt?

Gruss H.

[halo44]

Weiter oben hat schon jemand geschrieben: Kannst du bitte einmal die Ausgabe von timedatectl (aus dem Terminal, nicht durch udev-Skript) posten?

Das zeigt im NAS-Terminal jetzt

Code: Alles auswählen

               Local time: Mo 2021-09-20 17:17:06 CEST
           Universal time: Mo 2021-09-20 15:17:06 UTC
                 RTC time: Mo 2021-09-20 15:17:06
                Time zone: Europe/Berlin (CEST, +0200)
System clock synchronized: yes
              NTP service: active
          RTC in local TZ: no

Gruss H.

[reox]

Wird die komplette Ausgabe trotzdem noch benötigt?

Gruss H.

Der interessante teil ist wohl, was der unterschied von clock_gettime ist
aber poste mal bitte alles, das sollte ja auch nicht lang sein!

[halo44]

Hier die beiden Ausgaben, zunächst die Terminal-Ausgabe 41473

Dann die Ausgabe im Skript 41474 wobei diese Datei als Erstellungsdatum ebenfalls den 14.02.2019 trägt.

Gruss H.

[reox]

das ist echt oarg, tatsächlich liefert das ein anderes datum zurück:

Code: Alles auswählen

clock_gettime(CLOCK_REALTIME, {tv_sec=1550139129, tv_nsec=265725895}) = 0

Da kann ich mir überhaupt keinen reim drauf machen... wieso sollte das einmal tatsächlich das richtige datum liefern und mal nicht?!
offenbar wird auf der konsole noch /usr/lib/locale/locale-archive gelesen - was das für einen Unterschied macht versteh ich nicht - weil dann solte es ja mit LANG=C auch das resultat geben...
Auf die schnelle hab ich einen bug gefunden der so ähnlich klingt: https://git.kernel.org/pub/scm/linux/ke ... 2c3baa3ae4
evt ist das auch sowas und das lesen der datei verhindert, dass der Wert verwendet wird.

Kannst du probieren einen neueren Kernel zu verwenden? ggf ist das Problem im Kernel schon gelöst

[Tintom]

Hier die beiden Ausgaben, zunächst die Terminal-Ausgabe 41473

Dann die Ausgabe im Skript 41474 wobei diese Datei als Erstellungsdatum ebenfalls den 14.02.2019 trägt.

Gruss H.

Eine ganz banale Vermutung von mir: Du schreibst, du startest das System bei allen Änderungen neu. Kann es sein, dass das System die Uhrzeit beim Neustart vergisst (Batterie leer?)?
Nach dem Neustart beginnt das System zeitlich beim Urknall, hier also der 14.02. Diese Uhrzeit wird zunächst als Basis für die Systemzeit genommen. Während des Bootvorgangs wird dein udev-Skript abgearbeitet, wahrscheinlich jedoch bevor systemd-timesyncd sich die aktuelle Zeit aus dem Internet geholt hat. Sobald du dich eingeloggt hast, hat sich das System bereits eine Uhrzeit besorgt (siehe Ausgabe von timedatectl).

Was passiert, wenn du die Udev-Regel ausführst (d.h. den Stick einsteckst) nachdem du dich angemeldet hast und das System sich zeitlich synchronisiert hat (mit timedatectl vorher prüfen!)? Ändert das etwas?

[reox]

Dann müssten aber die Sekunden weitergezählt werden und wenn ich das richtig verstehe, kommt dort immer der selbe TImestamp zurück - oder nicht?

[halo44]

... Eine ganz banale Vermutung von mir: Du schreibst, du startest das System bei allen Änderungen neu. Kann es sein, dass das System die Uhrzeit beim Neustart vergisst (Batterie leer?)?
Nach dem Neustart beginnt das System zeitlich beim Urknall, hier also der 14.02. Diese Uhrzeit wird zunächst als Basis für die Systemzeit genommen. Während des Bootvorgangs wird dein udev-Skript abgearbeitet, wahrscheinlich jedoch bevor systemd-timesyncd sich die aktuelle Zeit aus dem Internet geholt hat. Sobald du dich eingeloggt hast, hat sich das System bereits eine Uhrzeit besorgt (siehe Ausgabe von timedatectl).

Was passiert, wenn du die Udev-Regel ausführst (d.h. den Stick einsteckst) nachdem du dich angemeldet hast und das System sich zeitlich synchronisiert hat (mit timedatectl vorher prüfen!)? Ändert das etwas?

Dass die Batterie leer ist, kann ich ausschließen. Ich schalte mein NAS spätabends per Cronjob aus. Hierbei vermittle ich dem NAS, dass es am nächsten Tag um 17:05 Uhr neu starten soll:

Code: Alles auswählen

echo `date '+%s' -d 'tomorrow 17:05:00'` > /sys/class/rtc/rtc0/wakealarm

Sollte die Batterie leer sein, wüsste mein NAS nicht wann es so weit ist.

Entscheidend aber ist, dass der USB-Stick beim Start des NAS bereits gesteckt ist. Stecke ich ihn erst nach vollständigen Start arbeitet date richtig, heute also

Code: Alles auswählen

Tue Sep 21 13:31:00 CEST 2021

Damit ist aber immer noch nicht geklärt, warum date nicht richtig arbeitet, wenn der Stick bereits gesteckt ist. Dies ist aber der Sinn der Sache, weil ich nicht unbedingt anwesend bin, wenn das NAS seine Aufgaben ausführen soll.

Auch noch dieser Hinweis, gestern 20.09.21 um 15:11:30 schrieb ich

Prüfe ich die Datenpartitionen auf dem NAS auf mount- und prüf-Vorgänge, so zeigen alle Partitionen ebenfalls das Datum 14.02.2019, allerdings mit unterschiedlichen Uhrzeiten.

Dieses falsche Datum zeigt sich im Terminal auch bei später gesteckten Stick

Code: Alles auswählen

root@NAS-01:~# tune2fs -l /dev/sda6 | egrep -i "Last"
Last mounted on:          /Daten-2
Last mount time:          Thu Feb 14 11:12:20 2019
Last write time:          Thu Feb 14 11:12:20 2019
Last checked:             Thu Feb 14 11:12:17 2019

Alles sehr seltsam.

Gruss H.

[uname]

Ich würde mal folgendes annehmen.

- die Batterie ist nicht leer
- beim Neustart bzw. im Schlafmodus wird die korrekte Uhrzeit verwendet
- dann wird sie beim Starten irgendwie falsch initialisiert
- jetzt läuft udev durch
- während des Starts wird sie dann wieder korrekt gesetzt

Vielleicht kann man irgendwie die Reihenfolge beim Boot ändern.
Oder wirklich statt "date" einen anderen Befehl verwenden siehe weiter oben.

[reox]

Aber dann sollte ein einfacher Test das klären können:

* das NAS aufdrehen
* verifizieren, dass auf der konsole das richtige datum mit `date` daherkommt
* dann den stick anstecken der die UDEV rule auslöst
* verifizieren, dass dort nicht der 14.02. ist

Heißt das auch, du hast die udev regel immer mit einem systemstart getestet?