Seltsames im Skript angestossen über udev-Regel

Vom einfachen Programm zum fertigen Debian-Paket, Fragen rund um Programmiersprachen, Scripting und Lizenzierung.
halo44
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 16.09.2021 14:25:54

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 Debiancoreutils. 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.

Benutzeravatar
minuseins
Beiträge: 123
Registriert: 21.05.2002 17:42:51
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von minuseins » 16.09.2021 18:42:37

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.
He who work root can fell trees and knowledge is no substitute for experience.

halo44
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 17.09.2021 10:04:32

minuseins hat geschrieben: ↑ zum Beitrag ↑
16.09.2021 18:42:37
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 Debiancoreutils 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.

Benutzeravatar
minuseins
Beiträge: 123
Registriert: 21.05.2002 17:42:51
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von minuseins » 17.09.2021 12:50:43

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

Gibt es da auch Unterschiede?
He who work root can fell trees and knowledge is no substitute for experience.

halo44
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 17.09.2021 14:09:52

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
Beiträge: 2459
Registriert: 06.06.2006 22:09:47
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von reox » 19.09.2021 11:37:21

halo44 hat geschrieben: ↑ zum Beitrag ↑
17.09.2021 10:04:32
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
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 19.09.2021 13:50:44

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
Beiträge: 2459
Registriert: 06.06.2006 22:09:47
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von reox » 20.09.2021 07:35:40

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.

Benutzeravatar
Tintom
Moderator
Beiträge: 3029
Registriert: 14.04.2006 20:55:15
Wohnort: Göttingen

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von Tintom » 20.09.2021 09:03:54

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
Beiträge: 12046
Registriert: 03.06.2008 09:33:02

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von uname » 20.09.2021 12:58:03

halo44 hat geschrieben: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 (Debiancoreutils) oder /sbin/hwclock (Debianutil-linux).

halo44
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 20.09.2021 14:45:06

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
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 20.09.2021 14:48:38

uname hat geschrieben: ↑ zum Beitrag ↑
20.09.2021 12:58:03
halo44 hat geschrieben: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 (Debiancoreutils) oder /sbin/hwclock (Debianutil-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
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 20.09.2021 15:11:30

reox hat geschrieben: ↑ zum Beitrag ↑
20.09.2021 07:35:40
... 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
Beiträge: 12046
Registriert: 03.06.2008 09:33:02

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von uname » 20.09.2021 15:44:51

Du könntest mal mit Debianstrace 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.
Zuletzt geändert von uname am 20.09.2021 15:51:09, insgesamt 2-mal geändert.

Benutzeravatar
Tintom
Moderator
Beiträge: 3029
Registriert: 14.04.2006 20:55:15
Wohnort: Göttingen

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von Tintom » 20.09.2021 15:47:47

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

halo44
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 20.09.2021 17:16:22

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
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 20.09.2021 17:18:29

Tintom hat geschrieben: ↑ zum Beitrag ↑
20.09.2021 15:47:47
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
Beiträge: 2459
Registriert: 06.06.2006 22:09:47
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von reox » 20.09.2021 20:11:10

halo44 hat geschrieben: ↑ zum Beitrag ↑
20.09.2021 17:16:22
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
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 21.09.2021 09:52:56

Hier die beiden Ausgaben, zunächst die Terminal-Ausgabe NoPaste-Eintrag41473

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

Gruss H.

reox
Beiträge: 2459
Registriert: 06.06.2006 22:09:47
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von reox » 21.09.2021 11:39:19

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

Benutzeravatar
Tintom
Moderator
Beiträge: 3029
Registriert: 14.04.2006 20:55:15
Wohnort: Göttingen

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von Tintom » 21.09.2021 12:15:38

halo44 hat geschrieben: ↑ zum Beitrag ↑
21.09.2021 09:52:56
Hier die beiden Ausgaben, zunächst die Terminal-Ausgabe NoPaste-Eintrag41473

Dann die Ausgabe im Skript NoPaste-Eintrag41474 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
Beiträge: 2459
Registriert: 06.06.2006 22:09:47
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von reox » 21.09.2021 12:52:19

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
Beiträge: 703
Registriert: 12.05.2015 15:19:13

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von halo44 » 21.09.2021 14:03:04

Tintom hat geschrieben: ↑ zum Beitrag ↑
21.09.2021 12:15:38
... 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
Beiträge: 12046
Registriert: 03.06.2008 09:33:02

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von uname » 21.09.2021 14:59:43

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
Beiträge: 2459
Registriert: 06.06.2006 22:09:47
Lizenz eigener Beiträge: MIT Lizenz

Re: Seltsames im Skript angestossen über udev-Regel

Beitrag von reox » 21.09.2021 15:24:03

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?

Antworten