Hmm ... das ist tatsächlich derselbe Grund für den Absturz.
In beiden Dumps ist es dieselbe Stelle, von wo die letzte Verzweigung (als Call) erfolgte, denn in beiden zeigt das "link register" auf dieselbe Rückkehradresse - nur die CPU, auf der dieser Worker-Thread im Kernel ausgeführt wird, ist einmal CPU0 und einmal CPU3.
Rich (BBCode):
<4>[ 1219.361455][F1] PC is at 0x0
<4>[ 1219.361472][F1] LR is at nf_queue_nf_hook_drop+0x30/0x3c
Es ist auch in beiden Fällen kein Versuch, auf diesen NULL-Pointer als Datenadresse zuzugreifen (da habe ich mich vorher geirrt) ... der nächste Befehl (PC -> Program Counter) soll angeblich an der Adresse 0x0 stehen und das ist natürlich Unsinn. Leider kann man den PC auch einfach direkt laden bei ARM, daher kriegt man auch nicht mehr ohne weiteres heraus, welche Instruktion genau es jetzt war, die als letzte abgearbeitet wurde - und dann eben dabei diesen Wert in den PC geladen hat.
Auch das ist wieder ungewöhnlich, wenn im Kernel irgendwo eine nicht aufgelöste Adresse herumschwirrt ... das kommt eigentlich nur dann vor, wenn da ein LKM nicht geladen wurde oder beim Linken diese Adresse als "weak" angesehen wurde - dann gibt das keinen Fehler, weil hinterher der Code dafür sorgen sollte, daß solche Adressen erst mal auf Gültigkeit geprüft werden, bevor man sie verwendet.
Leider kann man auch nichts in den Dumps erkennen (zumindest ich nicht), was da nun seitens vsFTPd das Problem triggert ... denn es handelt sich um einen Absturz in einem "Worker-Thread" des Kernels (das ist ein Thread-Pool, der immer wieder mit "kleinen Aufgaben" betraut wird und "reusable" ist, damit die Verwaltungsstrukturen nicht ständig abgeräumt und neu eingerichtet werden müssen) und da kann man eigentlich nur aus der "Aufrufkette" im Backtrace schlußfolgern, was da für eine Aufgabe zu erledigen war.
Hier ist das offenbar das Aufräumen irgendwelcher Netzwerk-Ressourcen und ich würde (anhand der restlichen Registerinhalte, die (auch) auf Adressen aus
net_namespace verweisen) behaupten, daß das
cleanup_net() als "Aufgabe" für diesen Worker-Thread:
Rich (BBCode):
<3>[ 1219.361620][F1] Classified pointer on registers:
<3>[ 1219.361629][F1] r0 : c5b78000 [slab: type:net_namespace size:3584 start:0xc5b78000+0x0 allocated by:0xc066f3c4 copy_net_ns+0x50/0x154]
<3>[ 1219.361700][F1] r1 : c5b55504 [slab: type:kmalloc-64 size:128 start:0xc5b55500+0x4 allocated by:0xc06b6680 nf_register_net_hook+0x1c/0xe0]
<3>[ 1219.361726][F1] r2 : cfa9a800 [task_struct(kworker/u8:1): cfa9a800+0x0]
<3>[ 1219.361823][F1] r4 : c5b78000 [slab: type:net_namespace size:3584 start:0xc5b78000+0x0 allocated by:0xc066f3c4 copy_net_ns+0x50/0x154]
<3>[ 1219.361886][F1] r5 : c5b55504 [slab: type:kmalloc-64 size:128 start:0xc5b55500+0x4 allocated by:0xc06b6680 nf_register_net_hook+0x1c/0xe0]
<3>[ 1219.361947][F1] r6 : c5b55500 [slab: type:kmalloc-64 size:128 start:0xc5b55500+0x0 allocated by:0xc06b6680 nf_register_net_hook+0x1c/0xe0]
<3>[ 1219.362006][F1] r7 : c5b7867c [slab: type:net_namespace size:3584 start:0xc5b78000+0x67c allocated by:0xc066f3c4 copy_net_ns+0x50/0x154]
<3>[ 1219.362066][F1] r8 : c5b78000 [slab: type:net_namespace size:3584 start:0xc5b78000+0x0 allocated by:0xc066f3c4 copy_net_ns+0x50/0x154]
<0>[ 1219.362180][F1] Backtrace:
<3>[ 1219.362206][F1] 3e94: [<c06b7aa0>] (0xc06b7aa0 nf_queue_nf_hook_drop+0x30/0x3c)
<3>[ 1219.362223][F1] 3eac: [<c06b6910>] (0xc06b6910 nf_unregister_net_hook+0xa8/0xc4)
<3>[ 1219.362240][F1] 3ebc: [<c06b6a84>] (0xc06b6a84 netfilter_net_exit+0x2c/0x50)
<3>[ 1219.362257][F1] 3ecc: [<c066e14c>] (0xc066e14c ops_exit_list+0x48/0x5c)
<3>[ 1219.362272][F1] 3f0c: [<c066f29c>] (0xc066f29c cleanup_net+0x168/0x240)
<3>[ 1219.362290][F1] 3f3c: [<c0243908>] (0xc0243908 process_one_work+0x1e4/0x34c)
<3>[ 1219.362306][F1] 3f64: [<c02445b4>] (0xc02445b4 worker_thread+0x2b0/0x3fc)
<3>[ 1219.362323][F1] 3fac: [<c0248a2c>] (0xc0248a2c kthread+0xe4/0xfc)
<3>[ 1219.362336][F1] 3Code: bad PC value
<3>[ 1219.362344][F1] 0Stack: (0xcf1b3e88 to 0xcf1b4000)
<3>[ 1219.362359][F1] 03e80: c5b55504 c09ef774 c5b55500 c06b6910 c0ae5a58 c09ef774
<3>[ 1219.362375][F1] 03ea0: c5b78000 cf1b3ed8 c0a3a154 c06b6a84 c5b78000 cf1b3ee0 c0ae5a78 c066e14c
<3>[ 1219.362391][F1] 03ec0: c0a3a190 c0ae5a78 cf1b3ee0 c066f29c cfdd9240 0084c100 c5b78020 c5b78020
<3>[ 1219.362407][F1] 03ee0: c5b78028 c5b78028 cf1b3f2c cfb3b0c0 c0a3a164 cf832640 00000000 cf862200
<3>[ 1219.362423][F1] 03f00: c0b98cc0 00000000 00000088 c0243908 cfb3b0c0 c0a3a164 00000080 cfb3b0c0
<3>[ 1219.362438][F1] 03f20: cf832640 cf832640 c09ec100 cfb3b0d8 cf832654 cf832688 00000088 c02445b4
<3>[ 1219.362453][F1] 03f40: cfa9a800 cfb3a380 00000000 cfb3b0c0 c0244304 00000000 00000000 00000000
<3>[ 1219.362468][F1] 03f60: 00000000 c0248a2c 00000000 00000000 00000000 cfb3b0c0 00000000 00000000
<3>[ 1219.362483][F1] 03f80: cf1b3f80 cf1b3f80 00000000 00000000 cf1b3f90 cf1b3f90 cf1b3fac cfb3a380
<3>[ 1219.362497][F1] 03fa0: c0248948 00000000 00000000 c0209e68 00000000 00000000 00000000 00000000
<3>[ 1219.362511][F1] 03fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
<3>[ 1219.362524][F1] 03fe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000
das aus
net/core/net_namespace.c ist. Warum das jetzt aber dazu führt, daß da irgendwo in
net/netfilter/nf_queue.c mit
nf_queue_nf_hook_drop() irgendein "queue handler" freigegeben werden soll, der offenbar gar nicht existiert, weiß ich auch nicht.
Um das jetzt weiter zu untersuchen (warum das tatsächlich crasht), müßte man sich die passenden Kernel-Quellen nehmen (ich habe jetzt nur mal schnell in denen des "vanilla kernel" gesucht, weil ich die passend vorliegen habe) und das genauer ansehen. Ich bin schon das erste Mal irritiert, was da AVM überhaupt für Settings beim Kernel-Build verwendet ... sowohl die Namespaces als auch Netfilter-Code hätte ich jetzt nicht unbedingt erwartet ... aber ich habe mich mit den ARM-Boxen bisher auch nie wirklich befaßt, was deren "Innereien" angeht.
Nur leider bringt das mich hinsichtlich einer Idee, warum der vsFTPd da nun einen Worker-Thread so "anstoßen" kann, daß der das System crasht, nicht einen Schritt weiter. Ich kann mir nicht vorstellen, daß da irgendwelche AVM-Patches im Socket-Code vorhanden sind (ähnlich den BUG_ON()-Statements, die man bei MIPS erst mal "wegpatchen" muß, wenn man den TUN-Treiber verwenden will), weil AVM solche Sockets eigentlich selbst sehr extensiv nutzt, um zwischen den eigenen Komponenten zu kommunizieren. Andererseits wüßte ich auch nicht, was da anderes als irgendein "buffer" (für irgendetwas, bis hin zu einem "packet") wieder "abgeräumt" werden sollte ... es ist ja kein
close() oder ähnliches als Syscall in einem der strace-Files zu sehen.
Es könnte allerdings sein, daß da zumindest schon mal ein solches
close() (oder irgendetwas anderes, was zum Abräumen irgendwelcher Ressourcen führt) aufgerufen wurde und genau in dessen Behandlung dann das System stirbt ... immerhin versucht das
strace ja eigentlich, das Ergebnis so eines Syscalls auch noch zu protokollieren und wartet deshalb (vermutlich) auf dessen Ende. Wenn das System dann stattdessen aber abstürzt, gibt es dieses erwartete Ende (also die Rückkehr aus dem Syscall) u.U. gar nicht mehr.
Wobei es das auch nicht wirklich sein kann (ich wollte es nur der Vollständigkeit halber erwähnen), denn die
strace-Files zeigen ja auch ein "ordentliches"
exit(), was dafür spricht, daß sich der vsFTPd aus irgendeinem anderen Grund "sauber" beendet (dazu zähle ich auch irgendwelche Ausgänge per Fehlerbehandlung) und das System erst danach dann stirbt - meinetwegen erst bei einem "lazy cleanup" per Kernel-Worker.
Irgendwie kriege ich das nicht so richtig zusammen ... selbst wenn man unterstellt, daß die ganzen Protokolle gleich an eine Stelle geschrieben wurden, wo sie auch einen Absturz überleben, so gibt es doch (eigentlich fast immer) auch noch irgendwelches Buffern (vom File-/Stream-Handling bis hin zum Filesystem), was das "echte Schreiben" irgendwie verzögert. Da müßte man also annehmen, daß zumindest die FS-Buffers bei der Kernel-Panic noch gesynct werden - wenn die Daten/Zeilen aus den Protokoll-Dateien es denn bis in den FS-Driver geschafft haben und nicht davor noch in irgendwelchen Buffer hängen.
Gleichzeitig sehen die
strace-Logs für die ersten beiden Prozesse aber auch so aus, daß sie "unvollständig" sind (nur 3150 ist tatsächlich komplett) ... denn die enden beide jeweils mit einem Funktionsnamen (wobei auch die Parameter-Listen noch fehlen, die KÖNNTEN noch im Buffer hängen) und zeigen nicht wirklich an, daß da der überwachte Prozess (und auch nicht das
strace) noch zu einem Ende gekommen wären. Ich weiß zwar (ohne Recherche) auch nicht, wie das
strace da seine Dateien behandelt, aber bei einem "normalen" Ende sollten die definitiv anders aussehen.
Bleibt also die These übrig, daß im Rahmen des
exit_group() (
https://man7.org/linux/man-pages/man2/exit_group.2.html) für Prozess 3150 irgendwo dieses
cleanup_net() angestoßen wird als "kernel task" (also eigentlich asynchron, denn der Syscall aus 3150 wird ja noch fertig bearbeitet, so daß
strace ihn protokollieren kann) und das dann das System zum Absturz bringt.
Als nächstes sollte man vielleicht mal nachsehen, was die (binäre) Eins, die da als letztes in 3150 in den Socket-Stream geschrieben wird, tatsächlich bedeutet (ich unterstellte bisher, daß das irgendwie "login successful with real account" heißen soll) - denn das ist ja auch wieder das letzte, was 3150 aus dem Socket liest. Die "Aufgabenverteilung" dürfte da so sein, daß 3150 die Control-Connection "bedient" und die Kommandos ausliest (und an dieser Stelle auch wartet, bis sowohl USER als auch PASS vorhanden sind) und dann diese beiden Werte über den Socket an den "parent process" (3148) sendet, der dann seinerseits die Account-Files verwendet, um die Gültigkeit zu prüfen. Und der schreibt dann als "Ergebnis" eben diese ominöse Eins in den Stream ... in 3150 ist danach gar kein weiterer Syscall zu sehen, bevor dann
exit_group(0) aufgerufen wird.
Das läßt mich fast vermuten, daß diese Eins doch eine andere Bedeutung hat ... da muß man dann wohl in den Quellen des vsFTPd noch einmal nachsehen, was die einzelnen Werte (es gibt da irgendeine Enum, wo die definiert werden und deren Namen fangen da alle mit einem kleinen "k" an) tatsächlich bedeuten. Und sei es nur um sicher zu gehen, daß dieser Wert nicht doch "Failure" bedeuten soll und wegen irgendwelcher Login-Beschränkungen/-Abhängigkeiten als Resultat geliefert wird. Das hier:
https://github.com/InfrastructureSe...f1028075d493cb9bae086dda4c3/twoprocess.c#L309 sollten die
read()-Aufrufe aus 3148 (Zeile 52 ff.) sein und hier:
https://github.com/InfrastructureSe...f1028075d493cb9bae086dda4c3/twoprocess.c#L390 wird dann wohl das Ergebnis (und die Eins ist dann doch
PRIV_SOCK_RESULT_OK:
https://github.com/InfrastructureSe...ebf1028075d493cb9bae086dda4c3/privsock.h#L173) zurückgegeben an 3150.
Hier wird das dann in 3150 gelesen ... und dann wird dieser Thread tatsächlich auch beendet, wenn es keine TLS-Verbindung sein soll:
https://github.com/InfrastructureSe...f1028075d493cb9bae086dda4c3/twoprocess.c#L201 - damit ist das also "normal", wenn 3150 an dieser Stelle beendet und abgeräumt wird. Damit sind wir dann wieder in 3148 zurück (das ist ja dessen Parent) und da wird als nächstes gewartet, daß irgendein anderen Prozess etwas tut - wie eben das Beenden von 3150:
https://github.com/InfrastructureSe...f1028075d493cb9bae086dda4c3/twoprocess.c#L393
Das Signalisieren dieses SIGCHLD, sieht man dann auch in der Datei zur 3148 (Zeile 85 - davor ist das
wait()) und dann sind wir tatsächlich wieder an der Stelle zurück im Code, wo ich gestern (oder vorgestern, ich weiß das nicht mehr so genau) auch "hängengeblieben" bin. Hier werden jetzt noch die neuen Signal-Handler installliert:
https://github.com/InfrastructureSe...f1028075d493cb9bae086dda4c3/twoprocess.c#L405, die man auch im Log sieht (Zeile 89) und danach soll dann ein neuer Thread eingerichtet werden:
https://github.com/InfrastructureSe...f1028075d493cb9bae086dda4c3/twoprocess.c#L406
Hier steht nun die Entscheidung an, ob das ein neuer Namespace sein soll (newnet) oder nicht ... aber in jedem Fall kommt es dann irgendwie zum
clone() ... angesichts des vorherigen
clone() in 3148 (Zeile 50) würde ich auch hier darauf tippen, daß die "newnet"-Variante gewählt wird, wo durch
CLONE_NEWNET als Option ein neuer Namespace eingerichtet werden soll.
Und ab hier ist es dann wieder mit dem Verfolgen im Code und im Log Essig ... irgendwo innerhalb des
clone()-Aufrufs (der bei irgendeinem Ende wie Zeile 50 aussehen sollte), stirbt dann das System. Nun ist es ja so, daß (aus dem Kopf, da grabe ich mich jetzt nicht durch den Kernel-Code) VOR dem Start neuer Prozesse/Threads, erst mal die alten abgeräumt werden, die zu diesem Zeitpunkt komplett beendet sind. Angesichts der Adressen/Funktionen aus dem Kernel-Dump würde ich daher darauf tippen, daß hier 3150 komplett entfernt werden soll (der hatte ja auch schon seinen eigenen Namespace in Zeile 50 erhalten, da macht das dann sogar wieder Sinn, wenn beim Abräumen auch Code zum Aufräumen in den Namespaces zur Ausführung gelangt) und daß es dabei dann zu dem Problem kommt, was den Worker-Thread und im Ergebnis den Kernel abstürzen läßt.
Ohne das jetzt bis ins Detail anzusehen ... wenn die Stelle, wo das andere
clone() erfolgte, dabei auch den Parameter
isolate_network für die Entscheidung für oder gegen
CLONE_NEWNET heranziehen sollte und das Problem tatsächlich im Aufräumen der Namespaces liegt, dann könnte es einen Versuch wert sein, das mal mit
isolate_network=no zu probieren, wobei ich jetzt auch keine Lust mehr habe, mir das im Detail anzusehen, was da anhand von Angaben in der Konfiguration und den Standardvorgaben im Moment herauskommen könnte ... ich gehe einfach mal davon aus, daß hier am Ende
isolate_network=yes wirksam ist (warum, ist mir eigentlich egal).
Wenn diese These stimmt und der Absturz des Kernels ohne die BENUTZUNG der Namespaces nicht erfolgt, dann wäre zumindest mal ein Workaround gefunden ... wobei auch dann die Ursache des Problems weiterhin im Dunklen liegt und die Tatsache, daß ein Userland-Programm durch Verwendung von
CLONE_NEWNET vielleicht das gesamte System abschießen kann (auch wenn das in der AVM-Theorie sicherlich ein "geschlossenes System" sein sollte), wäre einigermaßen erschreckend. Ich habe aber auch keinen wirklichen Bock (weil ich nicht eine einzige IPQ-Box besitze oder verwalte), mich da jetzt weiter schlau zu machen, wie weit das Handling an dieser Stelle durch AVM- oder andere Patches gegenüber dem Vanilla-Kernel verändert wurde.
Was man (wenn man die Firmware ohnehin modifiziert) noch mal probieren könnte, um die These (neben dem Versuch ohne
isolate_network) zu überprüfen, wäre die Verwendung von Namespaces an anderer Stelle (ein eher selten genutztes Feature), wobei dafür der Freetz-(NG-)BusyBox wohl ohnehin die Applets fehlen. Ich habe bisher auch nur ein einziges Skript "veröffentlicht", was mit Namespaces arbeitet (
https://github.com/PeterPawn/YourFritz/blob/main/tools/get_page) und das dann auch noch mit solchen im Filesystem ... was per se auch anderer Code im Kernel ist. Daher gibt's dazu von mir jetzt auch keine "Anleitung", wie man das testen könnte (das Internet hat bestimmt einiges zu Netzwerk-Namespaces zu bieten) - vielleicht überrascht uns ja jemand mit einem solchen Test zur Bestätigung (oder auch zum Widerlegen meiner Annahme).
Ich habe jetzt auch keinen Bock mehr, mir das selbst noch einmal durchzulesen (das war schon recht ermüdend, vor allem, weil man durch verschiedene Fundstellen in den Logs und den Quelltexten wechseln mußte) ... ich hoffe, es ist nicht zu wirr geraten und wenn jemand grammatikalische oder orthographische Probleme findet, darf er sie auch (für sich) behalten. Danke.
Was mich jetzt nur noch interessieren würde, wäre eben die Frage, ob es ohne
isolate_network funktioniert oder zumindest erst/schon an anderer Stelle zu einem (am besten auch anderen) Problem kommt ... dann wäre das Thema für mich durch. Ich war ohnehin überrascht (siehe oben), daß jemand im FRITZ!OS Namespaces "anbietet" (das hatte ich allerdings sogar schon bei den VR9-Modellen seit 3.10.xx gesehen und mir daher auch eine BusyBox mit passenden Applets gebaut, die in
yf_bin zu finden wäre) und daß die dann auch noch genutzt werden:
https://man7.org/linux/man-pages/man7/network_namespaces.7.html - wenn ich raten sollte, würde ich irgendwo im AVM-Code für den PA nach dem Grund suchen, warum der Worker-Thread da auf diese NULL (vermutlich eine nicht aufgelöste Referenz) trifft. Aber das ist tatsächlich nur spekulativ ... dazu müßte man sich in die passenden Quellen vertiefen und sich am besten sogar den Assembler-Code ansehen, der aus den C-Quellen generiert wurde (weil irgendwie ja die Null in den PC gelangen muß).
EDIT:
Und wenn man dann doch noch einmal in die
strace-Logs des "one process model"-Versuchs schaut (was ich davor nicht getan hatte, weil die mich ja nicht weiterbringen konnten hinsichtlich des Absturzes, wenn er da gar nicht auftritt), dann sieht man auch, daß dort das
clone() (4250, Zeile 2) auch ohne
CLONE_NEWNET erfolgt.
Irgendeinen Zusammenhang mit der Benutzerverwaltung (der andere Thread hier) kann man wohl praktisch ausschließen.
