Eine detaillierte Beschreibung der Fehlersuche aus der GitLab-Task, die zum Patch für den Linux-Kernel führte
Am 14. September meldete der GitLab-Support ein kritisches Problem, das bei einem unserer Kunden aufgetreten ist: Zuerst funktioniert GitLab einwandfrei, und dann erhalten Benutzer eine Fehlermeldung. Sie versuchten, einige Repositorys über Git zu klonen, und plötzlich erschien eine unverständliche Meldung über eine veraltete Datei: Veralteter Stale file error . Der Fehler blieb lange bestehen und funktionierte erst, als der Systemadministrator ls manuell im Verzeichnis selbst startete.
Ich musste die internen Mechanismen von Git und dem NFS-Netzwerkdateisystem untersuchen. Infolgedessen haben wir einen Fehler im Linux v4.0 NFS-Client gefunden. Trond Myklebust hat einen Patch für den Kernel geschrieben . Seit dem 26. Oktober ist dieser Patch im Haupt-Linux-Kernel enthalten .
In diesem Beitrag werde ich Ihnen erzählen, wie wir das Problem untersucht haben, in welche Richtung wir gedacht haben und mit welchen Tools wir den Fehler verfolgt haben. Wir waren inspiriert von der exzellenten Detektivarbeit von Oleg Dashevsky, die in dem Beitrag „Wie ich zwei Wochen lang in Ruby nach einem Gedächtnisleck gesucht habe “ beschrieben wurde .
Es ist auch ein großartiges Beispiel dafür, wie Open Source-Debugging ein Mannschaftssport ist, an dem viele Menschen, Unternehmen und Länder beteiligt sind. Das Motto von GitLab „ Jeder kann etwas beitragen “ gilt nicht nur für GitLab selbst, sondern auch für andere Open-Source-Projekte wie den Linux-Kernel.
Fehlerreproduktion
Wir haben NFS viele Jahre auf GitLab.com gespeichert, es dann jedoch nicht mehr für den Zugriff auf Repository-Daten auf Computern mit Anwendungen verwendet. Wir haben alle Git-Anrufe nach Gitaly verschoben . Wir unterstützen NFS für Clients, die ihre Installationen auf GitLab verwalten, jedoch noch nie auf dasselbe Problem wie der oben genannte Client gestoßen sind.
Der Kunde gab einige nützliche Hinweise :
- Vollständiger Fehlertext:
fatal: Couldn't read ./packed-refs: Stale file handle . - Anscheinend trat das Problem auf, als der Client die
git gc in Git mit dem Befehl git gc manuell startete. - Der Fehler verschwand, als der Systemadministrator das Dienstprogramm
ls im Verzeichnis startete. - Der Fehler verschwand, als der
git gc Prozess beendet wurde.
Es ist klar, dass die ersten beiden Punkte miteinander verbunden sind. Wenn Sie Änderungen an den Git-Zweig senden, erstellt Git einen schwachen Link - einen langen Dateinamen, der den Zweignamen für das Commit angibt. Beim Senden an den master wird beispielsweise eine Datei mit dem Namen refs/heads/master im Repository erstellt:
$ cat refs/heads/master 2e33a554576d06d9e71bfd6814ee9ba3a7838963
Der Befehl git gc führt mehrere Aufgaben aus. Beispielsweise werden diese schwachen Links (Refs) gesammelt und in eine einzelne Datei mit dem Namen Packed packed-refs . Dies beschleunigt die Arbeit etwas, da das Lesen einer großen Datei einfacher ist als bei vielen kleinen. Nach dem Ausführen des git gc die packed-refs Datei beispielsweise folgendermaßen aus:
# pack-refs with: peeled fully-peeled sorted 564c3424d6f9175cf5f2d522e10d20d781511bf1 refs/heads/10-8-stable edb037cbc85225261e8ede5455be4aad771ba3bb refs/heads/11-0-stable 94b9323033693af247128c8648023fe5b53e80f9 refs/heads/11-1-stable 2e33a554576d06d9e71bfd6814ee9ba3a7838963 refs/heads/master
Wie wird die packed-refs Datei erstellt? Um dies herauszufinden, haben wir den Befehl strace git gc ausgeführt, bei dem wir ein schwaches Glied hatten. Hier sind die Zeilen, die relevant sind:
28705 open("/tmp/libgit2/.git/packed-refs.lock", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 3 28705 open(".git/packed-refs", O_RDONLY) = 3 28705 open("/tmp/libgit2/.git/packed-refs.new", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 4 28705 rename("/tmp/libgit2/.git/packed-refs.new", "/tmp/libgit2/.git/packed-refs") = 0 28705 unlink("/tmp/libgit2/.git/packed-refs.lock") = 0
Systemaufrufe zeigten, dass der Befehl git gc :
packed-refs.lock . Dies teilt anderen Prozessen mit, dass die packed-refs gesperrt ist und sich nicht ändern kann.- Geöffnet
packed-refs.new . - Ich habe schwache Glieder in
packed-refs.new . - Umbenannt in
packed-refs.new packed-refs . packed-refs.new in packed-refs.new packed-refs . packed-refs.lock .- Schwache Glieder entfernt.
Der entscheidende Punkt hier ist der vierte, packed-refs Umbenennen, bei dem Git die packed-refs einführt. git gc sammelt nicht nur schwache Glieder, sondern führt auch eine viel ressourcenintensivere Aufgabe aus - es sucht und entfernt nicht verwendete Objekte. In großen Repositories kann dies länger als eine Stunde dauern.
Und wir haben uns gefragt: git gc in großen Repositories die Datei während der Reinigung offen? Wir haben die strace Protokolle untersucht, das Dienstprogramm lsof gestartet und git gc über den git gc Prozess git gc :
Wie Sie sehen können, wird die packed-refs ganz am Ende geschlossen, nachdem der möglicherweise lange Prozess der Garbage collect objects .
Es stellte sich also die folgende Frage: Wie verhält sich NFS, wenn die packed-refs auf einem Knoten geöffnet ist und der andere sie zu diesem Zeitpunkt umbenennt?
"Aus wissenschaftlichen Gründen" baten wir den Kunden, ein Experiment auf zwei verschiedenen Maschinen (Alice und Bob) durchzuführen:
1) Erstellen Sie auf dem gemeinsam genutzten NFS-Volume zwei Dateien: test1.txt und test2.txt mit unterschiedlichen Inhalten, damit Sie leichter zwischen ihnen unterscheiden können:
alice $ echo "1 - Old file" > /path/to/nfs/test1.txt alice $ echo "2 - New file" > /path/to/nfs/test2.txt
2) Auf Alices test1.txt sollte die Datei test1.txt geöffnet sein:
alice $ irb irb(main):001:0> File.open('/path/to/nfs/test1.txt')
3) Zeigen Sie auf Alices Computer kontinuierlich den Inhalt von test1.txt :
alice $ while true; do cat test1.txt; done
4) Führen Sie dann auf Bobs Computer den folgenden Befehl aus:
bob $ mv -f test2.txt test1.txt
Der letzte Schritt reproduziert, was git gc mit der packed-refs Datei macht, wenn eine vorhandene Datei überschrieben wird.
Auf dem Computer des Clients sah das Ergebnis ungefähr so aus:
1 - Old file 1 - Old file 1 - Old file cat: test1.txt: Stale file handle
Da ist! Wir scheinen das Problem auf kontrollierte Weise kontrolliert zu haben. Im selben Experiment auf einem Linux-NFS-Server trat dieses Problem jedoch nicht auf. Das Ergebnis wurde erwartet - nach dem Umbenennen wurde der neue Inhalt akzeptiert:
1 - Old file 1 - Old file 1 - Old file 2 - New file <--- RENAME HAPPENED 2 - New file 2 - New file
Woher kommt dieser Unterschied im Verhalten? Es stellt sich heraus, dass der Client Isilon NFS- Speicher verwendet hat, der nur NFS v4.0 unterstützt. Als wir die Verbindungseinstellungen mit dem Parameter vers=4.0 in /etc/fstab auf v4.0 änderten, ergab der Test ein anderes Ergebnis für den Linux-NFS-Server:
1 - Old file 1 - Old file 1 - Old file 1 - Old file <--- RENAME HAPPENED 1 - Old file 1 - Old file
Anstelle des veralteten Dateihandles Veraltetes Dateihandle zeigte Stale file handle Linux NFS v4.0-Server veralteten Inhalt an . Es stellt sich heraus, dass der Unterschied im Verhalten durch die NFS-Spezifikationen erklärt werden kann. Aus RFC 3010 :
Der Dateideskriptor ist möglicherweise veraltet oder läuft beim Umbenennen ab, jedoch nicht immer. Server-Implementierern wird empfohlen, Maßnahmen zu ergreifen, um sicherzustellen, dass Dateideskriptoren nicht ablaufen und auf diese Weise nicht ablaufen.
Mit anderen Worten, NFS-Server können festlegen, wie sie sich beim Umbenennen einer Datei verhalten Stale file error , und der NFS-Server gibt in solchen Fällen vernünftigerweise einen Stale file error . Wir haben vorgeschlagen, dass die Ursache des Problems dieselbe ist, obwohl die Ergebnisse unterschiedlich waren. Wir haben vermutet, dass es sich um eine Cache-Prüfung handelt, da das Dienstprogramm ls im Verzeichnis den Fehler behoben hat. Jetzt hatten wir ein reproduzierbares Testszenario und wandten uns an Experten - Linux NFS-Betreuer.
False Trace: Delegierung auf einem NFS-Server
Als wir es geschafft haben, den Fehler Schritt für Schritt zu reproduzieren, schrieb ich an die Linux-NFS-Kontakte, was wir gelernt haben. Ich korrespondierte eine Woche lang mit Bruce Fields, dem Linux-NFS-Server-Betreuer, und er schlug vor, dass der Fehler in NFS lag und ich den Netzwerkverkehr untersuchen musste. Er dachte, das Problem sei das Delegieren von Aufgaben auf dem NFS-Server.
Was ist eine Delegierung auf einem NFS-Server?
Kurz gesagt, die NFS v4-Version verfügt über eine Delegierungsfunktion, um den Dateizugriff zu beschleunigen. Der Server kann Lese- oder Schreibzugriff an den Client delegieren, sodass der Client den Server nicht ständig fragen muss, ob die Datei von einem anderen Client geändert wurde. Einfach ausgedrückt bedeutet das Delegieren einer Aufzeichnung, dass Sie jemandem Ihr Notizbuch leihen und sagen: "Sie schreiben hier, und ich werde es abholen, wenn ich bereit bin." Und eine Person muss nicht jedes Mal nach einem Notizbuch fragen, wenn Sie etwas schreiben müssen - sie hat völlige Handlungsfreiheit, bis das Notizbuch weggenommen wird. In NFS wird eine Anforderung zur Rückgabe eines Notizbuchs als Delegierungssperrung bezeichnet.
Ein Fehler beim Widerruf der NFS-Delegierung könnte das Problem des Stale file handle erklären. Denken test1.txt daran, wie test1.txt in Alices test1.txt geöffnet und dann durch test2.txt ersetzt wurde. Möglicherweise konnte der Server die Delegierung für test1.txt nicht widerrufen, was zu einem ungültigen Status führte. Um diese Theorie zu testen, haben wir den NFC-Verkehr mit dem Dienstprogramm tcpdump aufgezeichnet und mit Wireshark visualisiert.
Wireshark ist ein großartiges Open-Source-Tool zur Analyse des Netzwerkverkehrs, insbesondere zur Erkundung von NFS in Aktion. Wir haben den Trace mit dem folgenden Befehl auf einem NFS-Server aufgezeichnet:
tcpdump -s 0 -w /tmp/nfs.pcap port 2049
Dieser Befehl zeichnet den gesamten NFS-Verkehr auf, der normalerweise über den TCP-Port 2049 geleitet wird. Da unser Experiment mit NFS v4.1, jedoch nicht mit NFS v4.0 erfolgreich war, konnten wir das Verhalten von NFS im funktionierenden und im nicht funktionierenden Fall vergleichen. Bei Wireshark haben wir folgendes Verhalten festgestellt:
NFS v4.0 (veraltete Datei)
Dieses Diagramm zeigt, dass Alice in Schritt 1 test1.txt öffnet und einen NFS-Dateideskriptor mit der Kennung stateid 0x3000 empfängt. Wenn Bob versucht, die Datei umzubenennen, fordert der NFS-Server erneut zum Versuch auf, indem er die Nachricht NFS4ERR_DELAY , und er ruft die Delegierung von Alice über die Nachricht CB_RECALL (Schritt 3). Alice gibt die Delegierung zurück (DELEGRETURN in Schritt 4) und Bob versucht erneut, die RENAME Nachricht zu senden (Schritt 5). RENAME wird in beiden Fällen ausgeführt, aber Alice liest die Datei weiterhin mit demselben Deskriptor.
NFS v4.1 (Arbeitsfall)
Hier ist der Unterschied in Schritt 6 sichtbar. In NFS v4.0 (mit einer veralteten Datei) versucht Alice stateid dieselbe stateid . In NFS v4.1 (Arbeitsfall) führt Alice zusätzliche LOOKUP und OPEN Operationen aus, sodass der Server eine andere stateid . In v4.0 werden keine zusätzlichen Nachrichten gesendet. Dies erklärt, warum Alice veraltete Inhalte sieht - sie verwendet einen alten Deskriptor.
Warum entscheidet sich Alice plötzlich für einen zusätzlichen LOOKUP ? Anscheinend war der Rückruf der Delegation erfolgreich, aber anscheinend blieb ein Problem bestehen. Beispielsweise wird der Behinderungsschritt übersprungen. Um dies zu überprüfen, haben wir die NFS-Delegierung auf dem NFS-Server selbst mit diesem Befehl ausgeschlossen:
echo 0 > /proc/sys/fs/leases-enable
Wir haben das Experiment wiederholt, aber das Problem ist nicht verschwunden. Wir haben sichergestellt, dass das Problem nicht auf dem NFS-Server oder der Delegierung liegt, und beschlossen, den NFS-Client im Kernel zu untersuchen.
Tiefer graben: Linux NFS-Client
Die erste Frage, die wir den NFS-Betreuern beantworten mussten, war:
Bleibt dieses Problem in der neuesten Kernel-Version bestehen?
Das Problem trat in den Kerneln CentOS 7.2 und Ubuntu 16.04 mit den Versionen 3.10.0-862.11.6 bzw. 4.4.0-130 auf. Beide Kerne blieben jedoch hinter der neuesten Version zurück, die zu diesem Zeitpunkt 4,19-rc2 betrug.
Wir haben die neue virtuelle Maschine Ubuntu 16.04 auf der Google Cloud Platform (GCP) bereitgestellt, den neuesten Linux-Kernel geklont und die Kernel-Entwicklungsumgebung eingerichtet. Wir haben die .config Datei mit menuconfig und menuconfig überprüft:
- Der NFS-Treiber wird als Modul kompiliert (
CONFIG_NFSD=m ). - Die korrekten GCP-Kernelparameter sind korrekt angegeben.
Genetics verfolgt die Entwicklung in Echtzeit von Drosophila, und mit dem ersten Element konnten wir schnell Korrekturen am NFS-Client vornehmen, ohne den Kernel neu zu starten. Der zweite Punkt garantierte, dass der Kernel nach der Installation gestartet wird. Glücklicherweise waren wir mit den Standard-Kernel-Parametern zufrieden.
Wir haben dafür gesorgt, dass das Problem der veralteten Datei in der neuesten Kernel-Version nicht behoben wurde. Wir fragten uns:
- Wo genau tritt das Problem auf?
- Warum passiert dies in NFS v4.0, aber nicht in v4.1?
Um diese Fragen zu beantworten, haben wir uns mit dem NFS-Quellcode befasst. Wir hatten keinen Kernel-Debugger, also haben wir zwei Arten von Aufrufen an den Quellcode gesendet:
pr_info() ( printk ).dump_stack() : Zeigt den Stack-Trace für den aktuellen Funktionsaufruf an.
Als erstes haben wir beispielsweise eine Verbindung zur Funktion nfs4_file_open() in fs/nfs/nfs4file.c :
static int nfs4_file_open(struct inode *inode, struct file *filp) { ... pr_info("nfs4_file_open start\n"); dump_stack();
Natürlich könnten wir dprintk mit dynamischem Linux-Debugging dprintk oder rpcdebug , aber wir wollten unsere eigenen Nachrichten hinzufügen, um nach Änderungen zu rpcdebug .
Nach jeder Änderung haben wir das Modul neu kompiliert und es mit den folgenden Befehlen im Kernel neu installiert:
make modules sudo umount /mnt/nfs-test sudo rmmod nfsv4 sudo rmmod nfs sudo insmod fs/nfs/nfs.ko sudo mount -a
Mit dem NFS-Modul konnten wir Experimente wiederholen und Nachrichten empfangen, um den NFS-Code zu verstehen. Sie können beispielsweise sofort sehen, was passiert, wenn die Anwendung open() aufruft:
Sep 24 20:20:38 test-kernel kernel: [ 1145.233460] Call Trace: Sep 24 20:20:38 test-kernel kernel: [ 1145.233462] dump_stack+0x8e/0xd5 Sep 24 20:20:38 test-kernel kernel: [ 1145.233480] nfs4_file_open+0x56/0x2a0 [nfsv4] Sep 24 20:20:38 test-kernel kernel: [ 1145.233488] ? nfs42_clone_file_range+0x1c0/0x1c0 [nfsv4] Sep 24 20:20:38 test-kernel kernel: [ 1145.233490] do_dentry_open+0x1f6/0x360 Sep 24 20:20:38 test-kernel kernel: [ 1145.233492] vfs_open+0x2f/0x40 Sep 24 20:20:38 test-kernel kernel: [ 1145.233493] path_openat+0x2e8/0x1690 Sep 24 20:20:38 test-kernel kernel: [ 1145.233496] ? mem_cgroup_try_charge+0x8b/0x190 Sep 24 20:20:38 test-kernel kernel: [ 1145.233497] do_filp_open+0x9b/0x110 Sep 24 20:20:38 test-kernel kernel: [ 1145.233499] ? __check_object_size+0xb8/0x1b0 Sep 24 20:20:38 test-kernel kernel: [ 1145.233501] ? __alloc_fd+0x46/0x170 Sep 24 20:20:38 test-kernel kernel: [ 1145.233503] do_sys_open+0x1ba/0x250 Sep 24 20:20:38 test-kernel kernel: [ 1145.233505] ? do_sys_open+0x1ba/0x250 Sep 24 20:20:38 test-kernel kernel: [ 1145.233507] __x64_sys_openat+0x20/0x30 Sep 24 20:20:38 test-kernel kernel: [ 1145.233508] do_syscall_64+0x65/0x130
Was sind diese do_dentry_open und vfs_open ? Linux verfügt über ein virtuelles Dateisystem ( VFS ), eine Abstraktionsschicht, die eine gemeinsame Schnittstelle für alle Dateisysteme bietet. In der VFS-Dokumentation heißt es:
VFS implementiert open (2), stat (2), chmod (2) und andere Systemaufrufe. Das VFS-System verwendet das an sie übergebene Pfadnamenargument, um den Cache nach Verzeichniseinträgen (Dentry-Cache oder Dcache) zu durchsuchen. Dies bietet eine sehr schnelle Suchmaschine, die den Pfadnamen (oder Dateinamen) in ein bestimmtes Dentry konvertiert. Dentry befindet sich im RAM und wird niemals auf der Festplatte gespeichert - sie dienen nur der Leistung.
Und es wurde uns klar - was ist, wenn das Problem im Dentry-Cache liegt?
Wir haben festgestellt, dass der Dentry-Cache normalerweise in fs/nfs/dir.c Wir waren besonders an der Funktion nfs4_lookup_revalidate() interessiert und haben sie als Experiment früher zum nfs4_lookup_revalidate() :
diff --git a/fs/nfs/dir.cb/fs/nfs/dir.c index 8bfaa658b2c1..ad479bfeb669 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1159,6 +1159,7 @@ static int nfs_lookup_revalidate(struct dentry *dentry, unsigned int flags) trace_nfs_lookup_revalidate_enter(dir, dentry, flags); error = NFS_PROTO(dir)->lookup(dir, &dentry->d_name, fhandle, fattr, label); trace_nfs_lookup_revalidate_exit(dir, dentry, flags, error); + goto out_bad; if (error == -ESTALE || error == -ENOENT) goto out_bad; if (error)
Und in diesem Experiment ist kein veraltetes Dateiproblem aufgetreten! Schließlich haben wir den Trail angegriffen.
Um herauszufinden, warum das Problem in NFS v4.1 nicht aufgetreten ist, haben wir jedem if Block in dieser Funktion pr_info() -Aufrufe hinzugefügt. Wir haben mit NFS v4.0 und v4.1 experimentiert und in Version v4.1 eine spezielle Bedingung gefunden:
if (NFS_SB(dentry->d_sb)->caps & NFS_CAP_ATOMIC_OPEN_V1) { goto no_open; }
Was ist NFS_CAP_ATOMIC_OPEN_V1 ? Dieser Kernel-Patch besagt, dass dies eine Funktion von NFS v4.1 ist, und der Code in fs/nfs/nfs4proc.c bestätigt, dass dieser Parameter in v4.1, aber nicht in v4.0 enthalten ist:
static const struct nfs4_minor_version_ops nfs_v4_1_minor_ops = { .minor_version = 1, .init_caps = NFS_CAP_READDIRPLUS | NFS_CAP_ATOMIC_OPEN | NFS_CAP_POSIX_LOCK | NFS_CAP_STATEID_NFSV41 | NFS_CAP_ATOMIC_OPEN_V1
Daher haben sich die Versionen unterschiedlich verhalten - in Version goto no_open ruft goto no_open mehr Überprüfungen in der Funktion nfs_lookup_revalidate() , und in Version nfs4_lookup_revalidate() Funktion nfs4_lookup_revalidate() früher zurückgegeben. Und wie haben wir das Problem gelöst?
Lösung
Ich sprach über unsere Ergebnisse auf der NFS-Mailingliste und schlug einen primitiven Patch vor . Eine Woche später schickte Trond Myklebust eine Reihe von Patches mit Fehlerkorrekturen an die Mailingliste und fand ein weiteres verwandtes Problem in NFS v4.1 .
Es stellt sich heraus, dass das Update für den NFS v4.0-Fehler tiefer in der Codebasis lag als wir dachten. Trond hat es im Patch gut beschrieben :
Es muss sichergestellt werden, dass Inode und Dentry beim Öffnen einer bereits geöffneten Datei korrekt überprüft werden. Im Moment überprüfen wir weder NFSv4.0 noch zweimal, da die geöffnete Datei zwischengespeichert wird. Lassen Sie uns dies beheben und geöffnete Dateien nur in besonderen Fällen zwischenspeichern, um geöffnete Dateien wiederherzustellen und die Delegierung zurückzugeben.
Wir haben sichergestellt, dass dieses Update das veraltete Dateiproblem löst, und Fehlerberichte an die Ubuntu- und RedHat- Teams gesendet.
Wir haben gut verstanden, dass die Änderungen noch nicht in der stabilen Kernel-Version enthalten sind, und haben daher eine vorübergehende Lösung für dieses Problem in Gitaly hinzugefügt . Wir haben experimentiert und überprüft, dass der Kernel beim Aufrufen von stat() in der Datei packed-refs die umbenannte Datei im Dentry-Cache überprüft. Der Einfachheit halber haben wir dies in Gitaly für jedes Dateisystem implementiert, nicht nur für NFS. Die Validierung wird nur einmal durchgeführt, bevor Gitaly das Repository öffnet, und für andere Dateien gibt es bereits andere stat() -Aufrufe.
Was haben wir gelernt?
Ein Fehler kann sich in jeder Ecke des Software-Stacks verstecken, und manchmal müssen Sie ihn außerhalb der Anwendung suchen. Wenn Sie nützliche Verbindungen in der Open Source-Welt haben, wird dies Ihre Arbeit erleichtern.
Vielen Dank an Trond Myuklebust für die Behebung des Problems und an Bruce Fields für die Beantwortung unserer Fragen und die Unterstützung bei der Ermittlung von NFS. Für diese Reaktionsfähigkeit und Professionalität schätzen wir die Community der Open Source-Entwickler.