[erledigt] Systemd File corruption detected - journalctl --verify

Du hast Probleme mit Deinem eMail-Programm, Webbrowser oder Textprogramm? Dein Lieblingsprogramm streikt?
Antworten
Benutzeravatar
OrangeJuice
Beiträge: 616
Registriert: 12.06.2017 15:12:40

[erledigt] Systemd File corruption detected - journalctl --verify

Beitrag von OrangeJuice » 11.03.2021 11:07:16

Weiß jemand wie "File corruption detected" zustande kommt? Was bedeutet das genau?

Ich habe das häufig und bei verschiedenen Systemen. Ich habe gelesen, dass es teilweise per Browser passieren kann, wenn dieser irgendetwas nicht lesbares ablegt. Weiß da jemand mehr zu?

Ich habe mir extra einen key angelegt "journalctl --setup-keys" und diesen key dann mit "journalctl --verify --verify-key="meinkey"" überprüft.

Code: Alles auswählen

journalctl --verify-key=""
PASS: /var/log/journal/8bu...../user-1000.journal
150cc88: Data object's entry array not sorted                    
File corruption detected at /var/log/journal/8bu...../system.journal:154f838 (of 25165824 bytes, 88%).
FAIL: /var/log/journal/8bu...../system.journal (Ungültige Nachricht)
Zuletzt geändert von OrangeJuice am 16.03.2021 15:08:27, insgesamt 2-mal geändert.

Benutzeravatar
MSfree
Beiträge: 10686
Registriert: 25.09.2007 19:59:30

Re: Systemd File corruption detected - journalctl --verify

Beitrag von MSfree » 11.03.2021 11:38:37

OrangeJuice hat geschrieben: ↑ zum Beitrag ↑
11.03.2021 11:07:16
Weiß jemand wie "File corruption detected" zustande kommt?
Da journalctl im Spiel ist, dürfte es sich um das binäre Systemlog handeln, das hier korrupt ist.
Was bedeutet das genau?
Korrupt heißt hier, daß die Inhalte der Logs nicht vollständig sind.
Ich irgendwo gelesen, dass es teilweise per Browser passieren kann
Kann ich mir nicht vorstellen. Browser loggen nicht ins Systemlog, können daher diese Daeien auch nicht beschädigen.

Die Beschädigung entsteht am ehesten, wenn der Rechner nicht ordnungsgemäß runtergefahren wird und dann halbfertig geschriebene Einträge entstehen, weil der Rechner z.B. abgestürzt ist oder hart ausgeschaltet wurde.

Benutzeravatar
edmund
Beiträge: 113
Registriert: 27.12.2020 13:13:26

Re: Systemd File corruption detected - journalctl --verify

Beitrag von edmund » 11.03.2021 13:51:03

Die alten Logs kannste löschen

journalctl --vacuum-time=2d

zB löscht alles bis auf die letzten zwei Tage. Dann abwarten, ob es wieder kommt.

Benutzeravatar
OrangeJuice
Beiträge: 616
Registriert: 12.06.2017 15:12:40

Re: Systemd File corruption detected - journalctl --verify

Beitrag von OrangeJuice » 11.03.2021 14:02:19

PC heruntergefahren und wieder gestartet, danach steht direkt folgendes:

Code: Alles auswählen

4eac90: Tag failed verification                                  
File corruption detected at /var/log/journal/8bu.../user-1000.journal:4eac90 (of 8388608 bytes, 61%).
FAIL: /var/log/journal/8bu.../user-1000.journal (Ungültige Nachricht)
PASS: /var/log/journal/8bu.../system.journal
=> Validated from Thu 2021-03-11 13:27:33 CET to Thu 2021-03-11 15:19:06 CET, final 1min 9.895640s entries not sealed.
Jetzt sieht es wieder anders aus:

Code: Alles auswählen

4eac90: Tag failed verification                                  
File corruption detected at /var/log/journal/8bu.../user-1000.journal:4eac90 (of 8388608 bytes, 61%).
FAIL: /var/log/journal/8bu.../user-1000.journal (Ungültige Nachricht)
586900: Data object's entry array not sorted                     
File corruption detected at /var/log/journal/8bu.../system.journal:5a0c30 (of 8388608 bytes, 70%).
FAIL: /var/log/journal/8bu.../system.journal (Ungültige Nachricht)

Benutzeravatar
OrangeJuice
Beiträge: 616
Registriert: 12.06.2017 15:12:40

Re: Systemd File corruption detected - journalctl --verify

Beitrag von OrangeJuice » 12.03.2021 09:08:28

Nachdem gestern wieder direkt die Fehler auftraten, habe ich die Logs gelöscht und einen neuen Key angelegt.
Damit lief es eigentlich ganz gut über einige Neustarts hinweg und auch nach dem Ausschalten trat nichts auf.

Heute habe ich nur KeepassXC und den Firefox(Flatpak, weil mir der von Debian ausgelieferte Firefox immer abgestürzt ist) aufgemacht und nur eine Internetseite geöffnet und eingeloggt.
Danach war das Log wieder korrupt.

Das passiert aber nicht nur mit Debian Testing, sondern auch mit Ubuntu 20.04.

Code: Alles auswählen

PASS: /var/log/journal/8bu.../user-1000.journal
872ed8: Data object's entry array not sorted                     
File corruption detected at /var/log/journal/8bu.../system.journal:888860 (of 16777216 bytes, 53%).
FAIL: /var/log/journal/8bu.../system.journal (Ungültige Nachricht)

pferdefreund
Beiträge: 3791
Registriert: 26.02.2009 14:35:56

Re: Systemd File corruption detected - journalctl --verify

Beitrag von pferdefreund » 12.03.2021 10:05:49

Eventuell Ram defekt ? Mach mal nen Memtest. Hatte auch schon kaputte Archive und Ursache war defektes Ram. Wenn da im Cache ein Bit umkippt, wars das schon - besonders bei binären Daten. Platte sollte man auch mal prüfen, am besten aus einem Live-System.

Benutzeravatar
OrangeJuice
Beiträge: 616
Registriert: 12.06.2017 15:12:40

Re: Systemd File corruption detected - journalctl --verify

Beitrag von OrangeJuice » 13.03.2021 11:55:10

Den Arbeitsspeicher hatte ich vor zwei Monaten mal überprüft, ist alles okay. Heute hatte ich Memtest 1 Stunde laufen lassen, mehr wollte ich zur Zeit nicht, Memtest muss dann ein anderes Mal durchlaufen. SSDs sind auch okay.

Ich hatte gestern die Logs nochmals gelöscht, danach trat den ganzen Tag lang nichts auf. Heute, bevor ich das LAN-Kabel angeschlossen habe, war alles okay, dann habe ich nur den Browser verwendet und paar Seiten aufgerufen.
Danach war das Log wider korrupt.

Auf was kann denn so eine "File corruption" mit "Data object's entry array not sorted" und "tag/entry realtime timestamp out of synchronization" hindeuten?
Ist das bedenklich oder "passiert einfach"?

Code: Alles auswählen

PASS: /var/log/journal/8bu.../user-1000.journal
=> Validated from Sat 2021-03-13 10:28:18 CET to Sat 2021-03-13 10:29:25 CET, final 1h 10min 58.266823s entries not sealed.
e55880: Data object's entry array not sorted                     
File corruption detected at /var/log/journal/8bu.../system@....journal:e92a78 (of 16777216 bytes, 91%).
FAIL: /var/log/journal/8bu.../system@.....journal (Ungültige Nachricht)
447020: tag/entry realtime timestamp out of synchronization      
File corruption detected at /var/log/journal/8bu.../system.journal:447020 (of 8388608 bytes, 53%).
FAIL: /var/log/journal/8bu.../system.journal (Ungültige Nachricht)
PASS: /var/log/journal/8bu.../user-1000@....journal
=> Validated from Fri 2021-03-12 10:54:44 CET to Sat 2021-03-13 10:06:30 CET, final 21min 22.848249s entries not sealed.

willy4711

Re: Systemd File corruption detected - journalctl --verify

Beitrag von willy4711 » 14.03.2021 08:20:36

Mal bei mir im Journal gesucht:

Code: Alles auswählen

 $ journalctl -b|grep brow
Mär 14 06:45:34 XFCE audit[819]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="torbrowser_tor" pid=819 comm="apparmor_parser"
Mär 14 06:45:34 XFCE audit[817]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cups-browsed" pid=817 comm="apparmor_parser"
Mär 14 06:45:34 XFCE audit[812]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="torbrowser_firefox" pid=812 comm="apparmor_parser"
Mär 14 06:45:34 XFCE kernel: audit: type=1400 audit(1615700734.813:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="torbrowser_tor" pid=819 comm="apparmor_parser"
Mär 14 06:45:34 XFCE kernel: audit: type=1400 audit(1615700734.813:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cups-browsed" pid=817 comm="apparmor_parser"
Mär 14 06:45:35 XFCE audit[1197]: AVC apparmor="DENIED" operation="capable" profile="/usr/sbin/cups-browsed" pid=1197 comm="cups-browsed" capability=23  capname="sys_nice"
Mär 14 06:45:36 XFCE systemd[1320]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Mär 14 06:45:36 XFCE gpg-agent[1439]: using fd 6 for browser socket (/run/user/1000/gnupg/S.gpg-agent.browser)
Mär 14 06:45:36 XFCE gpg-agent[1439]: listening on: std=4 extra=5 browser=6 ssh=3
Mär 14 06:45:37 XFCE gpg-agent[1442]: using fd 6 for browser socket (/run/user/1000/gnupg/S.gpg-agent.browser)
Mär 14 06:45:37 XFCE gpg-agent[1442]: listening on: std=4 extra=5 browser=6 ssh=3

Vermutung im dunkel gestochert:
Ich würde mal en Flatpak-Browser gegen einen "richtigen" z.B. von Mozilla tauschen.
Kommt die Korruption eventuell zustande, wenn du Keepass aktiviert hast ?

Ich überblicke das Zusammenwirken von Apparmor / GnuPG / Keepass in keiner Weise, deshalb ist es auch nur einen Vermutung.

Aber vielleicht mal im Journal suchen.
Frage: Was versprichst du dir davon, das Journal mit einem key zu sichern ?

Benutzeravatar
OrangeJuice
Beiträge: 616
Registriert: 12.06.2017 15:12:40

Re: Systemd File corruption detected - journalctl --verify

Beitrag von OrangeJuice » 14.03.2021 09:23:19

Ich habe genau wegen Problemen mit dem Firefox, Flatpak gewählt. In gewissen Abständen ist der Browser aus dem Nichts heraus einfach abgeschmiert oder ich wurde komplett aus der Wayland Session geschmissen. Unter Ubuntu 20.04 hat das Apparmor Profil für Firefox ganz gut geholfen, damit habe ich eigentlich keinen Absturz gehabt. Ansonsten traten auch dort die Abstürze auf(also ohne Apparmor enforce usr.bin.firefox). Ich muss mal schauen, es war in Grub noch "intel_iommu=off iommu=soft" aktiviert. Das habe ich herausgenommen damit die und schaue, ob es nun weiter die Logs korrupten Logs gibt.

Manchmal sind die Logs definitiv korrupt, nachdem das System(ohne Internetanschluss) gestartet wurde. Keepass scheint das nicht zu sein, entweder passiert es nach dem der PC gestartet wurde oder wenn ich den Browser offen habe. KeepassXC habe ich selten geöffnet und die korrupten Logs passierten ja teilweise am laufenden Band.

Das mit dem secret key wird hier ganz gut beschrieben:
The systemd journal has an optional feature, known as Forward Secure Sealing, which defends against retrospective modification of log messages. Log messages added to the journal are signed with a secret key, and at regular intervals this key is securely deleted and a new key is chosen. A hacker who compromises the system can access the currently valid sealing key and use it to change the logs in the current interval, but has no way of finding out the valid key for previous time periods, meaning that it is impossible to forge a valid signature. Quelle

willy4711

Re: Systemd File corruption detected - journalctl --verify

Beitrag von willy4711 » 14.03.2021 09:58:53

OrangeJuice hat geschrieben: ↑ zum Beitrag ↑
14.03.2021 09:23:19
Das mit dem secret key wird hier ganz gut beschrieben:
Schon klar. Aber wovor willst du dich da schützen ? Hast du irgendein sicherheitskritisches System am laufen ?
Ich würde die Keys erstmal deaktivieren und dann sehen, was passiert:
OrangeJuice hat geschrieben: ↑ zum Beitrag ↑
14.03.2021 09:23:19
Manchmal sind die Logs definitiv korrupt, nachdem das System(ohne Internetanschluss) gestartet wurde.
D.h. Du kannst die Logs nach dem Booten schon nicht mehr öffnen ?
Passiert das mit /ohne Key ?
Vielleicht mal überprüfen:

Code: Alles auswählen

systemctl list-units|grep journal
Und dann den Status der einzelnen Units ?

Benutzeravatar
OrangeJuice
Beiträge: 616
Registriert: 12.06.2017 15:12:40

Re: Systemd File corruption detected - journalctl --verify

Beitrag von OrangeJuice » 14.03.2021 10:55:55

Ist ein "normaler" Intel Desktop PC(10.Gen) mit Debian Bullseye. Keys sind gelöscht. Passiert mit und ohne Key. In grub "intel_iommu=off iommu=soft" oder mit Hardware-Iommu macht auch keinen Unterschied. "security_lockdown_lsm_early lockdown=confidentiality"(secureboot) ist auch noch aktiviert und möchte ich ungern herausnehmen, das hatte auch nie wirklich Probleme bereitet.
Ich habe gerade wieder das korrupte Log direkt nach dem Start, vor dem Ausschalten hatte ich noch "--verify" durchlaufen lassen, da war das Log okay(ohne Secret-Key).

Ich habe halt keine Ahnung wie ich das deuten soll, ist das bedenklich?

Code: Alles auswählen

systemctl list-units|grep journal
  systemd-journal-flush.service                                                             loaded active exited    Flush Journal to Persistent Storage                                          
  systemd-journald.service                                                                  loaded active running   Journal Service                                                              
  systemd-journald-audit.socket                                                             loaded active running   Journal Audit Socket                                                         
  systemd-journald-dev-log.socket                                                           loaded active running   Journal Socket (/dev/log)                                                    
  systemd-journald.socket                                                                   loaded active running   Journal Socket

Code: Alles auswählen

journalctl --verify
390438: Data object references invalid entry at 53af38           
File corruption detected at /var/log/journal/8bu.../user-1000.journal:53add0 (of 8388608 bytes, 65%).
FAIL: /var/log/journal/8bu.../user-1000.journal (Ungültige Nachricht)
PASS: /var/log/journal/8bu.../system.journal
Was mir in dem Log auffällt ist folgendes, davon gibt es sehr viele Einträge:

Code: Alles auswählen

org.gnome.SettingsDaemon.Sound.service: Succeeded.
Mär 14 10:11:32 user gnome-shell[919]: Attempting to call back into JSAPI during the sweeping phase of GC. This is most likely caused by not destroying a Clutter actor or Gtk+ widget with ::destroy signals connected, but can also be caused by using the destroy(), dispose(), or remove() vfuncs. Because it would crash the application, it has been blocked and the JS callback not invoked.
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: == Stack trace for context 0x55da5eacd150 ==
Mär 14 10:11:32 user gnome-shell[919]: The offending signal was destroy on Gjs_ui_appDisplay_FolderGrid 0x55da60c80f70.
...
Mär 14 10:24:00 user gnome-shell[1864]: == Stack trace for context 0x558f0d755150 ==
Mär 14 10:24:00 user gnome-shell[1864]: The offending signal was destroy on Gjs_ui_appDisplay_AppIcon 0x558f0f64f510.
Mär 14 10:24:00 user gnome-shell[1864]: Attempting to call back into JSAPI during the sweeping phase of GC. This is most likely caused by not destroying a Clutter actor or Gtk+ widget with ::destroy signals connected, but can also be caused by using the destroy(), dispose(), or remove() vfuncs. Because it would crash the application, it has been blocked and the JS callback not invoked.
Zuletzt geändert von OrangeJuice am 14.03.2021 15:40:40, insgesamt 1-mal geändert.

Benutzeravatar
jph
Beiträge: 1049
Registriert: 06.12.2015 15:06:07
Lizenz eigener Beiträge: MIT Lizenz
Wohnort: Greven/Westf.

Re: Systemd File corruption detected - journalctl --verify

Beitrag von jph » 14.03.2021 11:04:11

An und für sich mag ich systemd...

Code: Alles auswählen

jan@t460s:~$ journalctl --verify
aa6170: Data object's entry array not sorted                                                            
File corruption detected at /run/log/journal/2411479b2ba04fc485d6f23df8cc26b4/system.journal:e75918 (of 15388672 bytes, 98%).
FAIL: /run/log/journal/2411479b2ba04fc485d6f23df8cc26b4/system.journal (Ungültige Nachricht)
PASS: /run/log/journal/2411479b2ba04fc485d6f23df8cc26b4/system@a8ad1bd4ee064caa9469c74c0588ccd5-0000000000000001-0005bd2db4791883.journal
Entweder ist im Speicher ein Bit gekippt, oder aber diese „Journal Verification“ scheint Mist zu sein. Ich tippe auf letzteres, denn Bitkipper im Hauptspeicher würden sich auch anderweitig bemerkbar machen.

willy4711

Re: Systemd File corruption detected - journalctl --verify

Beitrag von willy4711 » 14.03.2021 11:23:21

Also jetzt hab ich das verify auch mal gemacht:

Code: Alles auswählen

1b9cf78: Invalid entry item (5/29 offset: 000000                    
1b9cf78: Invalid object contents: Ungültige Nachricht               
File corruption detected at /var/log/journal/d3183aefaece487590ec39f41cee5f47/system@0005bc724011b122-2adcc1ca456e7ff5.journal~:1b9cf78 (of 33554432 bytes, 86%).
FAIL: /var/log/journal/d3183aefaece487590ec39f41cee5f47/system@0005bc724011b122-2adcc1ca456e7ff5.journal~ (Ungültige Nachricht)
Das betrifft bei mir aber eine Sicherungs- Datei (*.journal~)(was auch immer das ist) die eigentlichen Journal Dateien (*.journal) sind ok.
Hab das mit den in diesen Zeitraum erstellten Journaldateien überprüft nach der Liste mit

Code: Alles auswählen

journalctl --list-boots

Benutzeravatar
OrangeJuice
Beiträge: 616
Registriert: 12.06.2017 15:12:40

Re: [erledigt] Systemd File corruption detected - journalctl --verify

Beitrag von OrangeJuice » 16.03.2021 15:10:03

Ich stelle das Thema auf "erledigt". Ich denke, man müsste dann wohl einen Bugreport aufmachen, damit man herausbekommt wie und warum die Logs korrupt werden und --verify fehlschlägt.

Antworten