Denn wenn DECT immer aktiv ist, auch wenn die Box nichts anderes zu tun hat, dann ist DECT eben auch das, was durch den Crash als erstes in Mitleidenschaft gezogen wird und Folgefehler auslöst.
Stimmst Du denn wenigstens zu, daß die anderen beiden CPU-Cores (zumindest im "FASTIRQ-Status" und in den Backtraces) GAR NICHTS machen zum Zeitpunkt des Problems?
CPU 0:
Rich (BBCode):
<3>[ 2587.527286][1]CPU: 0 Pid: 0, comm: swapper/0
<3>[ 2587.532507][1] Tainted: P O (4.1.52 #1)
<4>[ 2587.538081][1]PC is at bcm_arm_cpuidle_wfi_enter+0x8/0x10
<4>[ 2587.543476][1]LR is at cpuidle_enter_state+0xd0/0x224
<3>[ 2587.548524][1]pc :[<c035a480>] lr :[<c0332bcc>] psr: 00000093
<3>[ 2587.548524][1]sp : c067df70 ip : 00000000 fp : c06797c0
<3>[ 2587.559996][1]r10: c06ad95c r9 : 0000025a r8 : 534f4149
<3>[ 2587.565736][1]r7 : df7c0ec0 r6 : c04b4c14 r5 : 00000001 r4 : c06ad9fc
<3>[ 2587.572691][1]r3 : c035a478 r2 : 00000001 r1 : c06ad95c r0 : c06c1fa0
<3>[ 2587.579648][1]Flags: nzcv IRQs off FIQs on Mode SVC_32 ISA ARM Segment kernel
<3>[ 2587.587125][1]Control: 10c5387d Table: 0b81404a DAC: 00000015
<3>[ 2587.593112][1]Classified pointer on registers:
<3>[ 2587.597552][1]r3 : c035a478 bcm_arm_cpuidle_wfi_enter+0x0/0x10
<3>[ 2587.603421][1]r6 : c04b4c14 cpu_online_mask+0x0/0x4
<3>[ 2587.608318][1]r7 : df7c0ec0 [page: type:reserved]
<3>[ 2587.613188][1]Backtrace:
<3>[ 2587.615733][1]1f6c: [<c035a480>] (0xc035a480 bcm_arm_cpuidle_wfi_enter+0x8/0x10)
<3>[ 2587.623131][1]1f9c: [<c0332bcc>] (0xc0332bcc cpuidle_enter_state+0xd0/0x224)
<3>[ 2587.630184][1]1fbc: [<c0056c44>] (0xc0056c44 cpu_startup_entry+0x208/0x268)
<3>[ 2587.637150][1]3Code: e5930000 e12fff1e f57ff04b e320f003 (e1a00002)
<3>[ 2587.643587][1]0Stack: (0xc067df70 to 0xc067e000)
<3>[ 2587.648288][1]0df60: 5a94d148 0000025a c06762a0 c067c000
<3>[ 2587.656810][1]0df80: c067e4b8 c04b4c14 df7c0ec0 c067dfa0 c0676280 c06ad95c c06797c0 c0056c44
<3>[ 2587.665332][1]0dfa0: c0678eb8 c06b8182 c06797c0 00000000 00000000 ffffffff 00000000 c0640c80
<3>[ 2587.673854][1]0dfc0: ffffffff ffffffff c064067c 00000000 00000000 c066fd30 c06ba258 c067e45c
<3>[ 2587.682375][1]0dfe0: c066fd2c c0683454 0000404a 410fc075 00000000 0000807c 00000000 00000000
<3>[ 2587.690949][1]Classified pointer on stack:
<3>[ 2587.695041][1]c04b4c14 cpu_online_mask+0x0/0x4
<3>[ 2587.699503][1]df7c0ec0 [page: type:reserved]
<3>[ 2587.703783][1]c0056c44 cpu_startup_entry+0x208/0x268
<3>[ 2587.708813][1]c0640c80 start_kernel+0x3b0/0x3bc
<3>[ 2587.713341][1]c064067c unknown_bootoption+0x0/0x1cc
<3>[ 2587.718345][1]
CPU 2:
Rich (BBCode):
<3>[ 2587.720007][1]CPU: 2 Pid: 0, comm: swapper/2
<3>[ 2587.725227][1] Tainted: P O (4.1.52 #1)
<4>[ 2587.730796][1]PC is at bcm_arm_cpuidle_wfi_enter+0x8/0x10
<4>[ 2587.736190][1]LR is at cpuidle_enter_state+0xd0/0x224
<3>[ 2587.741237][1]pc :[<c035a480>] lr :[<c0332bcc>] psr: 00000093
<3>[ 2587.741237][1]sp : dec41fa8 ip : 00000000 fp : c06797c0
<3>[ 2587.752708][1]r10: c06ad95c r9 : 0000025a r8 : 5ec0c748
<3>[ 2587.758449][1]r7 : df7d8ec0 r6 : c04b4c14 r5 : 00000001 r4 : c06ad9fc
<3>[ 2587.765404][1]r3 : c035a478 r2 : 00000001 r1 : c06ad95c r0 : c06c5fa0
<3>[ 2587.772361][1]Flags: nzcv IRQs off FIQs on Mode SVC_32 ISA ARM Segment kernel
<3>[ 2587.779838][1]Control: 10c5387d Table: 124ec04a DAC: 00000015
<3>[ 2587.785817][1]Classified pointer on registers:
<3>[ 2587.790257][1]r3 : c035a478 bcm_arm_cpuidle_wfi_enter+0x0/0x10
<3>[ 2587.796180][1]r6 : c04b4c14 cpu_online_mask+0x0/0x4
<3>[ 2587.801089][1]r7 : df7d8ec0 [page: type:reserved]
<3>[ 2587.805985][1]Backtrace:
<3>[ 2587.808536][1]1fa4: [<c035a480>] (0xc035a480 bcm_arm_cpuidle_wfi_enter+0x8/0x10)
<3>[ 2587.815939][1]1fd4: [<c0332bcc>] (0xc0332bcc cpuidle_enter_state+0xd0/0x224)
<3>[ 2587.823004][1]1ff4: [<c0056c44>] (0xc0056c44 cpu_startup_entry+0x208/0x268)
<3>[ 2587.829976][1]3Code: e5930000 e12fff1e f57ff04b e320f003 (e1a00002)
<3>[ 2587.836418][1]0Stack: (0xdec41fa8 to 0xdec42000)
<3>[ 2587.841124][1]01fa0: 6615a76e 0000025a c06762a0 dec40000 c067e4b8 c04b4c14
<3>[ 2587.849651][1]01fc0: df7d8ec0 dec41fd8 c0676280 c06ad95c c06797c0 c0056c44 c0678eb8 c06b8182
<3>[ 2587.858180][1]01fe0: c06797c0 00000000 1ec2804a c06ba2c0 00000000 000095cc cec63f32 b077e54c
<3>[ 2587.866851][1]Classified pointer on stack:
<3>[ 2587.870947][1]dec40000 [page: type:alloc]
<3>[ 2587.874965][1]c04b4c14 cpu_online_mask+0x0/0x4
<3>[ 2587.879428][1]df7d8ec0 [page: type:reserved]
<3>[ 2587.883729][1]c0056c44 cpu_startup_entry+0x208/0x268
<3>[ 2587.888784][1]cec63f32 [page: type:alloc by:0xc017f7b0 squashfs_copy_cache+0xdc/0x154]
<3>[ 2587.896713][1]
Das ist auch in beiden Protokollen gleich - ob sogar Adressen identisch sind, habe ich gar nicht erst verglichen. Aber wenn so ein Absturz in dem Moment auftreten soll, wo eine CPU in einen Idle-State wechselt (was hier schon mal zwei von drei Cores bei BEIDEN Absturzprotokollen machen), dann würde so eine Box kaum noch ins Arbeiten kommen.
Abgesehen davon, tritt die Exception ja auch BEIDE Male auf der CPU 1 auf:
Rich (BBCode):
<1>[ 2586.180475][1]Unable to handle kernel paging request at virtual address 02197c14
bzw.
<1>[ 2005.559704][1]Unable to handle kernel paging request at virtual address 9fe42d78
und man kann auch NACHLESEN, daß diese Exception im Rahmen einer IRQ-Behandlung aufgetreten ist:
Rich (BBCode):
<0>[ 2587.918750][1]Kernel panic - not syncing: Fatal exception in interrupt
bzw.
<0>[ 2005.785984][1]Kernel panic - not syncing: Fatal exception in interrupt
Welcher Core befindet sich nach dem jeweiligen Backtrace gerade im IRQ-Handling?
Rich (BBCode):
<3>[ 2586.406027][1]Backtrace:
[...]
<3>[ 2586.413101][1]1ec4: [<c006a0b4>] (0xc006a0b4 rcu_check_callbacks+0x1f4/0x8e8)
[...]
<3>[ 2587.036738][1]1ed4: [<c006c750>] (0xc006c750 update_process_times+0x38/0x64)
<3>[ 2587.043793][1]1efc: [<c0079f8c>] (0xc0079f8c tick_handle_periodic+0x28/0x88)
<3>[ 2587.050847][1]1f04: [<c0334c60>] (0xc0334c60 arch_timer_handler_phys+0x28/0x30)
<3>[ 2587.058159][1]1f1c: [<c0062cec>] (0xc0062cec handle_percpu_devid_irq+0x6c/0x84)
<3>[ 2587.065470][1]1f24: [<c005ed4c>] (0xc005ed4c generic_handle_irq+0x2c/0x3c)
<3>[ 2587.072352][1]1f3c: [<c005efe8>] (0xc005efe8 __handle_domain_irq+0x5c/0xb4)
<3>[ 2587.079323][1]1f5c: [<c000946c>] (0xc000946c gic_handle_irq+0x54/0x118)
bzw.
<3>[ 2005.774630][1]Backtrace:
<3>[ 2005.774653][1]1ea4: [<c0094798>] (0xc0094798 perf_event_task_tick+0x54/0x238)
<3>[ 2005.774665][1]1ec4: [<c0047648>] (0xc0047648 scheduler_tick+0x78/0xd0)
<3>[ 2005.774676][1]1ed4: [<c006c770>] (0xc006c770 update_process_times+0x58/0x64)
<3>[ 2005.774686][1]1efc: [<c0079f8c>] (0xc0079f8c tick_handle_periodic+0x28/0x88)
<3>[ 2005.774700][1]1f04: [<c0334c60>] (0xc0334c60 arch_timer_handler_phys+0x28/0x30)
<3>[ 2005.774711][1]1f1c: [<c0062cec>] (0xc0062cec handle_percpu_devid_irq+0x6c/0x84)
<3>[ 2005.774718][1]1f24: [<c005ed4c>] (0xc005ed4c generic_handle_irq+0x2c/0x3c)
<3>[ 2005.774725][1]1f3c: [<c005efe8>] (0xc005efe8 __handle_domain_irq+0x5c/0xb4)
<3>[ 2005.774734][1]1f5c: [<c000946c>] (0xc000946c gic_handle_irq+0x54/0x118)
Welche "Statistik" für die letzten IRQ-Behandlungen auf den drei Cores findet man im Text?
Rich (BBCode):
<3>[ 2587.453520][1]FASTIRQ-Status:
<3>[ 2587.456486][1] CPU0 CPU1 CPU2
<3>[ 2587.462001][1] 48: 0 0 0 Watchdog
<3>[ 2587.469198][1] 148: 0 641448 0 tdm_pcm consum:min 9 max 125 avg 26 dt:min 2066 max 108994 avg 4000 us
<3>[ 2587.483160][1] 250: 0 0 0 monitor/0
<3>[ 2587.490294][1] 251: 0 0 0 monitor/1
<3>[ 2587.497426][1] 252: 0 0 0 monitor/2
<3>[ 2587.504559][1]preempts: 0 0 0
<3>[ 2587.510128][1]spurious: 18 28 0
<3>[ 2587.515697][1] consum: 0.0 0.6 0.0 %
bzw.
<3>[ 2005.775685][1]FASTIRQ-Status:
<3>[ 2005.775692][1] CPU0 CPU1 CPU2
<3>[ 2005.775729][1] 48: 0 0 0 Watchdog
<3>[ 2005.775790][F1][DECTDRV_ERR] pcm count 0 != 107
<3>[ 2005.775831][1] 148: 0 496050 0 tdm_pcm consum:min 10 max 4852 avg 27 dt:min 1179 max 95402 avg 4000 us
<3>[ 2005.775895][1] 250: 0 0 0 monitor/0
<3>[ 2005.775901][1] 251: 0 0 0 monitor/1
<3>[ 2005.775907][1] 252: 0 0 0 monitor/2
<3>[ 2005.775913][1]preempts: 0 0 0
<3>[ 2005.775918][1]spurious: 19 13 0
<3>[ 2005.775923][1] consum: 0.0 0.7 0.0 %
Ich denke schon, daß dieses alles zunächst mal die Schlußfolgerung zuläßt, daß der einzige Core, der zu diesem Zeitpunkt überhaupt etwas zu tun hat, CPU 1 ist - ein Core, auf dem gerade nichts läuft, greift auch nicht auf irgendwelche Adressen im Speicher zu. Welcher Prozess auf der CPU lief, die überhaupt nennenswert irgendetwas (zu diesem Zeitpunkt) macht, sollte auch kaum in Frage stehen.
So ein Crash tritt ja auch nur dann auf, wenn die CPU irgendwelchen Code ausführt (der auch aus dem Speicher gelesen werden muß, wobei er ggf. - je nach Größe - auch lange im (Instruction-)Cache verbleiben kann, solange nichts anderes ihn verdrängt) und dabei auf irgendwelche Speicherinhalte zugreifen will (das wäre dann nicht mehr Code, sondern Daten, wofür es i.d.R. auch eigene Caches gibt bei der ARM-Architektur, iirc) - das passiert eben auch in der Behandlung von Unterbrechungen (aka
Interrupt-
Re
Quests).
Selbst wenn das nur die Behandlung eines Timer-Interrupts sein sollte, weil das komplette DECT-Timing da "von Hand" gemacht wird durch irgendeinen Prozess (beim TDMA sind nun mal Timeslots ziemlich exakt einzuhalten, was hohe Anforderungen an die Reaktionszeiten auf Interrupts stellt, weil die Timings nun auch wieder nicht so sind, daß man sich da einfach mal um einige Millisekunden "vertun" darf), dann wäre das immer noch der DECT-Treiber (bzw. "einer"), der da - allen Anzeichen nach - zu diesem Zeitpunkt aktiv ist/war.
Schaut man sich dann die beiden fehlgeschlagenen Speicherzugriffe noch einmal genau an:
Rich (BBCode):
<1>[ 2586.180475][1]Unable to handle kernel paging request at virtual address 02197c14
<1>[ 2586.187889][1]pgd = c0004000
<1>[ 2586.190767][1][02197c14] *pgd=00000000
<0>[ 2586.194351][1]Internal error: Oops: 5 [#1] PREEMPT SMP ARM
bzw.
<1>[ 2005.559704][1]Unable to handle kernel paging request at virtual address 9fe42d78
<1>[ 2005.567119][1]pgd = c0004000
<1>[ 2005.569996][1][9fe42d78] *pgd=00000000
<0>[ 2005.573577][1]Internal error: Oops: 805 [#1] PREEMPT SMP ARM
führen diese Adressen ja offensichtlich "ins Nichts" und haben damit auch nichts damit zu tun, daß es irgendein Problem beim Lesen aus dem physikalischen Speicher gibt (zumindest nicht als direkte Ursache für die Exception, höchstens beim Lesen falscher Werte, die dann weiterverarbeitet wurden).
Das müßte dann aber auch schon ein gewaltiger Zufall sein, wenn da einmal mind. ein Bit (bei der 0x9F...) und einmal mind. zwei Bits (denn mit 0x02... kommt man nur durch Setzen von mind. zwei Bits im ersten Nibble auf eine Adresse, wo Kernel-Code oder -Daten liegen würden) genau dann verändert würden beim Lesen, wenn sich das System in der IRQ-Behandlung (vermutlich ja innerhalb von
tdm_pcm) befindet und nicht auch bei anderen Gelegenheiten.
Auch wenn das Folgende meinerseits wieder "freie Interpretation" ist (mehr als z.B. das hier:
https://people.kernel.org/linusw/arm32-page-tables kenne ich da auch nicht) - das "page global directory" liegt da wohl an der Adresse 0xc0004000 (das ist Teil der MMU-Verwaltung, siehe Link hiervor) und für die virtuelle Adresse, die da jeweils angefragt war (die grün markierten Werte) fand sich dann im PGD offensichtlich kein Pointer auf einen passenden PTE (page table entry) - so würde ich jedenfalls (ohne den Blick in die Quellen) die Ausgabe interpretieren (da werden vermutlich die PTE dann einfach im Code traversiert und nach dem passenden Eintrag für die virt. Adresse gesucht, der hier jedoch nicht existiert).
Man müßte vermutlich tatsächlich mal in die Kernel-Quellen sehen, wobei die ARM-Cores von BCM im 32-Bit-Modus (und dem Dump nach arbeitet das System ja in einem solchen, ich sehe jedenfalls keinen Wert, der auf 64-Bit-Modus hinweist) schon einigermaßen vergleichbar arbeiten sollten und man daher wahrscheinlich sogar irgendwo im Vanilla-Kernel bei der Behandlung von RaspberryPi's nachsehen könnte, wie die Exception-Behandlung im Paging-Prozess aussieht - nur ist das auch einiges an Arbeit und außer vermehrtem Wissen erreicht man damit nichts wirklich, weil diese Kenntnis nur dann beim "Wahrsagen" helfen würde, wenn es eine andere, plausible(!) These gäbe, die sich mit der beißen würde, daß da irgendwelche sinnlosen Werte für einen Zugriff verwendet werden sollen (die sind sich ja nicht mal richtig ähnlich, die "angefragten" Adressen).
Da auch keines der sichtbaren Register einen Rückschluß zuläßt, auf wessen Inhalt die "berechnete" Adresse letztlich basiert (das wird vermutlich eine Kombination aus einer Basisadresse in einem Register und einem (falschen) Offset in einem anderen sein), kann man das auch nicht (zuverlässig) "ablesen" und ist auf ein paar "Schlußfolgerungen" angewiesen - auch hinsichtlich des Zeitpunkts, der durch den Dump der Register abgebildet wird. Am wahrscheinlichsten sind das die Registerinhalte zu dem Zeitpunkt, wo die Paging-Exception auftrat - dann wäre das irgendeine Instruktion in
perf_event_task_tick (wenn da nicht ein Kernel-Symbol zwischen dessen Start und den nächsten 84 Byte fehlt).
Was für mich hier auffällig ist, wäre die Tatsache, daß das Link-Register ($LR), welches üblicherweise die Rückkehradresse zum Aufrufer enthält (und zwar direkt und nicht als "Adresse, wo die Rückkehradresse steht", denn beim "branch with link" wird nur R15 (also $PC) nach R14 kopiert), denselben Inhalt hat wie der Stack-Pointer ($SP) - das KANN allerdings auch sein, weil man es wie ein normales GPR behandeln kann, solange man die Rückkehradresse nicht darin braucht (bzw. die irgendwo auf dem Stack abgelegt hat).
Komisch sieht es dennoch aus, FALLS es als Rücksprungadresse genutzt werden sollte - denn bei ordentlicher Sicherheit im Speicherzugriff sollten die Pages mit dem Stack eigentlich "nicht ausführbar" sein (damit sollten da auch keine Instruktionen stehen, die ein Rücksprung ausführen könnte) und die Pages mit Kernel-Code dann ihrerseits "nur lesbar". Ich weiß aber auch nicht sicher, wie die Stack-Verkettung bei ARM32 aussieht und müßte das selbst erst nachlesen.
Aber R15 (bzw. der Program Counter -> $PC) zeigt dann auch wieder sauber auf irgendwelche Instruktionen im Kernel-Code (weit unterhalb von 0xDExxxxxx bei 0xC0xxxxxx - wie praktisch alle "Sprungpunkte" im Backtrace für CPU 1 aus diesem Bereich stammen) - vor dem Backtrace der Funktionsaufrufe ist ja auch noch zu sehen, welche Adressen in welchen Registern auf Speicheradressen verweisen, mit denen die Speicherverwaltung des Kernels an dieser Stelle etwas anfangen konnte.
Es ist auch nicht wirklich bei beiden Protokollen ein Absturz an derselben Stelle - nur eben beide Mal in der IRQ-Behandlung und wenn da sooo unterschiedliche Adressen auftauchen, dann liegt die Vermutung schon nahe, daß diese dann aus Daten gewonnen wurden, die im Rahmen der IRQ-Behandlung irgendwo angefallen sind - ansonsten träten die Probleme ja regelmäßig auf.
Ich will auch gar nicht bezweifeln, daß sich DECT-Fehler danach ggf. noch weiter "hochschaukeln" (zumindest in dem Log vom 05.12.) - aber in beiden Fällen ist da - eben außer dem
DECTDRV (nach dem man aber auch in Quellen nicht suchen könnte, weil der ziemlich sicher "closed source" bei AVM ist) - gar kein anderer Prozess zu sehen, der arbeiten würde (und auch die CPU 1 kommt da ja nach den Pointern auf dem Stack aus einem
cpuidle_enter_state()-Aufruf, wenn's an die IRQ-Behandlung geht) und bekanntlich kann jemand, der nichts tut, auch nichts falsch machen ... und beide Probleme "starten" nun mal auch mit einer Nachricht
[DECTDRV_ERR] pcm count x != y von diesem Prozess.
Wenn da also - dem Dump nach - gar nichts anderes arbeitet, was sollte das denn dann noch sein, was da die Relevanz der Meldungen des
DECTDRV so in Frage stellen könnte, daß man zu der Feststellung:
Aber wenn dem so ist, dann ist das Argument, dass rund um den Crash ausschließlich DECT Fehler auftreten, nicht mehr so relevant.
gelangen sollte?
Selbstverständlich sind auf so einer Box (und mit einem "modernen" OS) STÄNDIG auch irgendwelche anderen Prozesse aktiv - nur eben nicht zu dem Zeitpunkt, wo auf eine nicht gemappte Adresse im Speicher zugegriffen werden sollte - sagt jedenfalls der Dump für die anderen beiden CPUs (s.o.) und die Tatsache, daß die Paging-Exception offenkundig auch auf CPU 1 auftrat.
Richtig witzig wäre das ja auch erst dann, wenn das tatsächlich gültige Adressen im Kernel-Kontext wären und dann von dort irgendwelcher Unsinn gelesen oder gar vom Kernel Mist an diese Stellen geschrieben würde.
