[Gelöst] Freetzen einer 7590 mit FW 7.12

[PeterPawn]

Dann versuche es doch noch einmal mit dem AVM-Recovery-Programm (und richtiger "Verkabelung").

Letztens hatten wir Berichte, daß jemand die Box unglücklich beim Schreiben eines TFFS-Images unterbrochen hatte und danach nur noch Unsinn im TFFS stand (EDIT: das war hier: https://www.ip-phone-forum.de/threads/7590-in-bootschleife.306149/post-2360965).

Wenn hier die Box schon mindestens bis S01-head kommt (da erst trägt sie das "154.07.12" ein), dann bleiben nur noch falsche Einstellungen oder tatsächlich ein Hardware-Defekt (bei einer neuen Box eher unwahrscheinlich) übrig.

Ich habe das jetzt jedenfalls so verstanden, daß Du bei den letzten Versuchen nicht mehr das AVM-Programm verwendet hast und nur das löscht Dir (automatisch) defekte Einstellungen. Wobei Du zuvor dann sicherstellen solltest (über EVA auslesen), daß das Environment komplett und lesbar ist (das schreibt das AVM-Programm dann wieder in die "environment.log", aber man kann auch vorher selbst nachsehen).

 

[Massa]

Das soll sicherlich eine 178 werden und wenn der Versuch mit dem "ping", wo irgendeine öffentliche IP dann antwortete, mit dieser Einstellung erfolgte, dann ist das nicht verwunderlich.

Das ware nur ein Schreibfehler hier im Forum.
Da ich bei der Box ja dann im adam2 lande, hat sie zumindest im Bootloader die 192.168.178.1

Ich verwende Windows 10 Pro nativ auf meinem Laptop, die Linux-Versuche waren über eine VM...
Die letzten Tests habe ich alle unter Windows gemacht, eben um die VM-Fehlerquelle auszuschalten.

Im Laptop habe ich eine LAN-Schnittstelle, an der direkt mit einem Kabel die 7590 hängt (und nur die), aktuell an deren LAN 4-Schnittstelle (hatte aber auch bereits LAN1 versucht).
Und ich habe eine W-LAN Schnittstelle, die über die 7490-Fritzbox mit dem Internet verbunden ist - wenn ich sie anhabe (kann diese mit einem Schalter abschalten).
Die Antwort dieser komischen Adresse kommt nur dann, wenn parallel zur LAN-Schnittstelle die W-LAN Schnittstelle an ist (nach meinem Netzwerkverständnis sollte da eigentlich eine 192.168'er Adresse nie geroutet werden - deswegen wundert mich das ja...)
Aber auch hier: die letzten Tests mache ich immer mit abgeschalteter W-LAN Schnittstelle.
Im Laptop sind auch noch VMWare Workstation und der OpenVPN-Client installiert - die erzeugen zwar auch Netzwerkschnittstellen, die sind aber aktuell auch inaktiv (zumal ja aktuell auch keinerlei VM läuft).

Und auch in diese Konstellation wird die Box weder vom AVM-Recovery noch vom EVA-Discover gefunden.
Nur die Methode mit dem Abwarten und händischem Abschicken des ftp-Kommandos in den ADAM rein funktioniert....

Und natürlich warte ich nach jedem Flash-Versuch ab, bis die Box von selber bootet - aber wie geschrieben, selbst ein "laaanges" Warten (obwohl die Box lt. Lichtorgel schon mehrmals neu gebootet hat) führt nicht mehr zum "Auftauchen" auf der LAN-Schnittstelle.
Ich kann jetzt mal noch die feste IP-Adresse wegnehmen und mal schauen, ob mein Laptop von der Fritzbox eine IP-Adresse bekommt...

 

[PeterPawn]

Das ware nur ein Schreibfehler hier im Forum.

DAS halte ich aber für Unsinn ... oder hast Du die ganzen anderen Protokolle (von "ipconfig" bis zur Routing-Table) in #18 auch "selbst verfaßt"? Da ist diese 187 noch mehrere Male zu lesen. Wobei das ja nun wieder nur ein virtueller Adapter auf dem VM-Host sein soll ... aber wenn das der Adapter ist, über den die Linux-VM mittels NAT ins lokale Netz gehen soll, paßt das irgendwie auch alles nicht. Aber das ist mittlerweile ja auch schon wieder Schnee von gestern ... als ich das mit der 187 gelesen hatte, kamst Du ja nach Deiner Aussage gar nicht mehr auf die Box.

Es ist schon ziemlich schwer, sich irgendwelche Gedanken zu machen, wenn praktisch schon beim Schreiben sich die Ergebnisse wieder ins Gegenteil verkehren und man gar nicht mehr hinterherkommt mit dem "Verständnis", was Du da eigentlich gerade machst.

Vielleicht solltest Du erst dann die nächsten Beiträge verfassen, wenn Du erfolgreich warst oder alles das, was Du noch testen möchtest, auch durch ist. Ansonsten ist es schon einigermaßen frustrierend, wenn man gar nicht mehr fertig wird mit dem Schreiben, weil sich schon wieder etwas verändert hat. Ich weiß auch nicht, ob es Dir aufgefallen ist ... aber in #24 beschreibst Du zum allerersten Mal in verständlichem Umfang, was Du da als System verwendest und wie Du es benutzt - zuvor waren das immer nur "Bröckchen" und man mußte sich irgendwie einen Reim darauf machen.

===========================================================================

Ich kann jetzt mal noch die feste IP-Adresse wegnehmen und mal schauen, ob mein Laptop von der Fritzbox eine IP-Adresse bekommt...

Mein Vorschlag wäre, daß Du Dir mal den oben verlinkten Thread zum Recovery ansiehst und ihn - Schritt für Schritt - abarbeitest. Dabei die Box am besten mit einem Switch mit dem PC verbinden und den PC auf "automatisch beziehen" stellen. Dann sollte das Interface nach kurzer Zeit eine APIPA-Adresse haben ... auch damit funktioniert das Recovery-Programm einwandfrei.

Zuvor solltest Du noch alle bereits vorhandenen Einträge in der Firewall für AVM-Recovery-Programme löschen ... es geht darum, daß das verwendete Programm seinerseits diese Freigaben noch einmal neu anfordern soll und daß Du dabei dann aufpaßt, diese sowohl für "private" als auch für "public" zu erteilen. Dann wird auch der erste Versuch (erwartbar) mißlingen ... im erwähnten Thread steht, woran das liegt und wie man es richtig macht.

Und wenn das dann immer noch nicht klappen will, dann suchst Du noch mal nach den beiden Dateien mit den Protokollen des AVM-Programms und stellst die hier rein (bei der "environment.log" kannst/solltest Du einige Daten maskieren, aber auch nicht komplett löschen).

 

[Massa]

DAS halte ich aber für Unsinn ... oder hast Du die ganzen anderen Protokolle (von "ipconfig" bis zur Routing-Table) in #18 auch "selbst verfaßt"?

Nein, natürlich nicht - ich meinte, wenn ich das im Fließtext geschrieben habe, war das ein Schreibfehler. Die Code-Sachen sind Copy & Paste...
Meine Zieladresse war beim ping etc. 192.168.178.1 und nicht 192.168.187.1.

Die 187.1 taucht auf, weil die eine virtuelle VMware-Schnittstelle eben diese Adresse hat - aber die ist nur aktiv, wenn eine VM läuft.
Und da ich ja jetzt versuche, so viel wie möglich Fehlerquellen auszuschalten ist bei meinen Tests jetzt imer nur noch die LAN-Schnittstelle aktiv (bzw. erst passiv und wird dann durch den Strom der FritzBox aktiviert).

Es ist schon ziemlich schwer, sich irgendwelche Gedanken zu machen, wenn praktisch schon beim Schreiben sich die Ergebnisse wieder ins Gegenteil verkehren und man gar nicht mehr hinterherkommt mit dem "Verständnis", was Du da eigentlich gerade machst.

Das tut mir leid, wenn das so chaotisch rüberkommt. ich versuche jetzt halt Schritt für Schritt weiterzukommen....

Mein Vorschlag wäre, daß Du Dir mal den oben verlinkten Thread zum Recovery ansiehst und ihn - Schritt für Schritt - abarbeitest. Dabei die Box am besten mit einem Switch mit dem PC verbinden und den PC auf "automatisch beziehen" stellen. Dann sollte das Interface nach kurzer Zeit eine APIPA-Adresse haben ... auch damit funktioniert das Recovery-Programm einwandfrei.

Den Thread mit dem Recovery habe ich gelesen, da kam ja auch der Tipp mit dem UNSETENV von "crash" und "firmware_info" her...
Aber ja, ich lese mir den Thread nochmal genau durch und versuche, nach ihm vorzugehen...

Zuvor solltest Du noch alle bereits vorhandenen Einträge in der Firewall für AVM-Recovery-Programme löschen ... es geht darum, daß das verwendete Programm seinerseits diese Freigaben noch einmal neu anfordern soll und daß Du dabei dann aufpaßt, diese sowohl für "private" als auch für "public" zu erteilen. Dann wird auch der erste Versuch (erwartbar) mißlingen ... im erwähnten Thread steht, woran das liegt und wie man es richtig macht.

Hmm, wenn die Firewall ausgeschaltet ist, sollte das doch immer funktionieren, oder?

Und wenn das dann immer noch nicht klappen will, dann suchst Du noch mal nach den beiden Dateien mit den Protokollen des AVM-Programms und stellst die hier rein (bei der "environment.log" kannst/solltest Du einige Daten maskieren, aber auch nicht komplett löschen).

Ich werde wieder berichten - bei den bisherigen Versuchen war die "environment.log" immer leer...

 

[Massa]

So, jetzt bin ich ein Stückchen weiter gekommen.
Nachdem ich die Windows-Firewall nicht nur für private, sondern auch für öffentliche Netzwerke abgeschaltet habe, findet auch das AVM-Recovery die Box - und zwar sowohl mit IPIPA-Adresse als auch mit fester 192.168.178.30-Adresse (bei ersterem fragt er vorher noch ab, welche Schnittstelle er nehmen soll).
Hier das ftp.log-Protokoll des erfolgreichen AVM-Recovery mit fester IP und verbunden über einen kleinen Switch, an dem der Laptop und die Fritzbox hängen (und sonst nichts):

0:18:061: 2.00 gitbuild:3524e9a
0:18:061: Registry: SYSTEM\CurrentControlSet\Services\TcpIp\Parameters\DisableDHCPMediaSense=1
0:18:061: recover-firmware-id:        226
0:18:061: recover-firmware-version:    154.07.12
0:18:374: check adapter(Intel(R) 82579LM Gigabit Network Connection) adapter 0x19: Ip: 192.168.178.30(255.255.255.0) (static)
0:18:374: compatible ipaddress (static) found: 192.168.178.30 on adapter 0x19
0:18:389: search on addr: 192.168.178.1
0:35:451: ---> read environment <---
0:35:561: open ftp 192.168.178.1 port 21
0:35:576: recv: 220 ADAM2 FTP Server ready
0:35:576: send: USER adam2
0:35:576: recv: 331 Password required for adam2
0:35:576: send: PASS adam2
0:35:576: recv: 230 User adam2 successfully logged in
0:35:576: send: SYST
0:35:576: recv: 215 AVM EVA Version 1.3578 0x0 0x46409
0:35:576: send: TYPE I
0:35:576: recv: 200 Type set to BINARY
0:35:576: send: MEDIA SDRAM
0:35:576: recv: 200 Media set to MEDIA_SDRAM
0:35:576: send: P@SW
0:35:576: recv: 227 Entering Passive Mode (192,168,178,1,12,8)
0:35:576: open ftp data 192.168.178.1 port 3080
0:35:576: send: RETR env
0:35:576: recv: 150 Opening BINARY data connection
0:35:686: recv: 226 Transfer complete
0:35:795: environment successfully readed(1376 bytes)
0:35:795: send: USER adam2
0:35:795: recv: 331 Password required for adam2
0:35:795: send: PASS adam2
0:35:795: recv: 230 User adam2 successfully logged in
0:35:795: send: SYST
0:35:795: recv: 215 AVM EVA Version 1.3578 0x0 0x46409
0:35:795: send: TYPE I
0:35:795: recv: 200 Type set to BINARY
0:35:795: send: MEDIA SDRAM
0:35:795: recv: 200 Media set to MEDIA_SDRAM
0:35:795: send: P@SW
0:35:795: recv: 227 Entering Passive Mode (192,168,178,1,12,3)
0:35:795: open ftp data 192.168.178.1 port 3075
0:35:795: send: RETR count
0:35:795: recv: 150 Opening BINARY data connection
0:35:858: recv: 226 Transfer complete
0:35:967: environment successfully readed(153 bytes)
0:35:967: send: BYE
0:35:967: recv: 221 Thank you for using the FTP service on ADAM2
0:35:967:     hardware-revision:    226
0:35:967:     firmware-version:    154.07.12
0:35:967:     urloader-version:    1.3578 (4578)
0:35:967:     oem:    avm
0:35:967:     provider:    
0:36:623: set defaultsettings mtd4 (size: 2036)
0:36:623: ---> write image (mtdnand) <---
0:36:733: open ftp 192.168.178.1 port 21
0:36:764: recv: 220 ADAM2 FTP Server ready
0:36:764: send: USER adam2
0:36:764: recv: 331 Password required for adam2
0:36:764: send: PASS adam2
0:36:764: recv: 230 User adam2 successfully logged in
0:36:764: send: SYST
0:36:764: recv: 215 AVM EVA Version 1.3578 0x0 0x46409
0:36:764: send: TYPE I
0:36:764: recv: 200 Type set to BINARY
0:36:764: send: MEDIA FLSH
0:36:764: recv: 200 Media set to MEDIA_FLASH
0:36:764: send: P@SW
0:36:764: recv: 227 Entering Passive Mode (192,168,178,1,12,13)
0:36:764: open ftp data 192.168.178.1 port 3085
0:36:764: clear flash-partition (mtdnand)
0:37:170: send: STOR mtdnand
0:37:170: recv: 150 Opening BINARY data connection
0:37:170: flash clear (mtdnand) ok : now send image
0:37:279: update flash-partition (mtdnand)
0:37:295: send image (size=2036) for mtd8
0:38:029: recv: 226 Transfer complete
0:38:029: flash write (mtd8) ok
0:38:154: successfully update of mtd8
0:38:154: send: BYE
0:38:154: recv: 221 Thank you for using the FTP service on ADAM2
0:38:186: nand: load filesystem and kernel image to RAM (size: 26708480)
0:38:186: ---> read environment <---
0:38:295: open ftp 192.168.178.1 port 21
0:38:795: recv: 220 ADAM2 FTP Server ready
0:38:795: send: USER adam2
0:38:795: recv: 331 Password required for adam2
0:38:795: send: PASS adam2
0:38:795: recv: 230 User adam2 successfully logged in
0:38:795: send: SYST
0:38:795: recv: 215 AVM EVA Version 1.3578 0x0 0x46409
0:38:795: send: TYPE I
0:38:795: recv: 200 Type set to BINARY
0:38:795: send: MEDIA SDRAM
0:38:795: recv: 200 Media set to MEDIA_SDRAM
0:38:795: send: P@SW
0:38:795: recv: 227 Entering Passive Mode (192,168,178,1,12,28)
0:38:795: open ftp data 192.168.178.1 port 3100
0:38:795: send: RETR env
0:38:795: recv: 150 Opening BINARY data connection
0:38:904: recv: 226 Transfer complete
0:39:014: environment successfully readed(1354 bytes)
0:39:014: send: BYE
0:39:014: recv: 221 Thank you for using the FTP service on ADAM2
0:39:014: ramload: savekernel activ for NAND
0:39:014: ---> write image mtd1 mtd1-base/size(500000/800000)ram-base/size(80000000/8000000) SquashFS(488a00) <---
0:39:123: open ftp 192.168.178.1 port 21
0:39:139: recv: 220 ADAM2 FTP Server ready
0:39:154: send: USER adam2
0:39:154: recv: 331 Password required for adam2
0:39:154: send: PASS adam2
0:39:154: recv: 230 User adam2 successfully logged in
0:39:154: send: SYST
0:39:154: recv: 215 AVM EVA Version 1.3578 0x0 0x46409
0:39:154: send: SETENV memsize 0x6687600
0:39:154: recv: 200 SETENV command successful
0:39:154: send: SETENV kernel_args_tmp mtdram1=0x86687600,0x88000000
0:39:154: recv: 200 SETENV command successful
0:39:154: send: TYPE I
0:39:154: recv: 200 Type set to BINARY
0:39:154: send: MEDIA SDRAM
0:39:154: recv: 200 Media set to MEDIA_SDRAM
0:39:154: send: P@SW
0:39:154: recv: 227 Entering Passive Mode (192,168,178,1,12,21)
0:39:154: open ftp data 192.168.178.1 port 3093
0:39:154: RAM-Load Image to 86687600 Filesystem: 86b10000
0:39:154: send: STOR 0x86687600 0x88000000
0:39:154: recv: 150 Opening BINARY data connection
0:39:154: now send image mtd1 to ram
0:39:170: send image (size=26708480) for mtd1
0:47:904: recv: 226 Transfer complete
0:47:904: load to ram (mtd1) ok
0:49:139: ----EOF---

Und hier die environment.log, die jetzt auch gefüllt ist (MAC-Adressen, Seriennummer und andere Sachen habe ich ausgeXXXXt):

HWRevision            226
HWSubRevision         4
ProductID             Fritz_Box_HW226
SerialNumber          JXXXXXXXXXX
annex                 B
autoload              yes
bootloaderVersion     1.3578
firstfreeaddress      0x85284A30
firmware_info         154.07.12
firmware_version      avm
flashsize             nor_size=0MB sflash_size=0KB nand_size=512MB
linux_fs_start        1
maca                  XX:XX:XX:XX:XX:D7
macb                  XX:XX:XX:XX:XX:D8
macwlan               XX:XX:XX:XX:XX:D9
macwlan2              XX:XX:XX:XX:XX:DA
macdsl                XX:XX:XX:XX:XX:D4
memsize               0x08000000
mtd0                  0x0,0x2C00000
mtd1                  0x500000,0xD00000
mtd2                  0x0,0x100000
mtd3                  0x100000,0x500000
mtd4                  0xD00000,0x1500000
mtd5                  0x1500000,0x20000000
my_ipaddress          192.168.178.1
prompt                Eva_AVM
provider              
tr069_passphrase      XXXXXXX
tr069_serial          XXXXXX-XXXXXXXX
usb_board_mac         XX:XX:XX:XX:XX:XX
usb_device_id         0x0000
usb_device_name       USB DSL Device
usb_manufacturer_name  AVM
usb_revision_id       0x0000
usb_rndis_mac         XX:XX:XX:XX:XX:XX
webgui_pass           xxxxxxxx
wlan_key              XX:XX:XX:XX:XX:XX
wlan_ssid             FRITZ!Box#7590#CF

Ich habe das jetzt einmal erfolgreich über die IPIPA-Schnittstelle und einmal über die feste IP durchgeführt und dann gewartet, bis sie wieder bootet...
I(Interessanterweise findet EVA-Discovery.ps1 die Box immer noch nicht...)
ch schrieb' oben: ich bin ein Stückchen weitergekommen - aber eben nur ein Stückchen, weil selbst jetzt ist die Box noch nicht wieder nach einem normalen Bootvorgang per Web-Interface erreichbar und sie rebootet immer noch nach kurzer Zeit.
Ich werde nochmals weiter im o.a. Thread nachlesen, ob da noch was drinsteht und weiter berichten...

Übrigens: ich habe nach dem Recovery auch noch Versuche mit EVA-discovery.ps1 durchgeführt - das findet die Box immer noch nicht...

 

[PeterPawn]

Übrigens: ich habe nach dem Recovery auch noch Versuche mit EVA-discovery.ps1 durchgeführt - das findet die Box immer noch nicht...

Angesichts der Vielzahl von Netzwerkschnittstellen glaube ich daran aber erst, wenn ich einen Mitschnitt im Netzwerk gesehen habe, wo die ausgehenden UDP-Pakete zu sehen sind und danach in demselben Mitschnitt auch noch eine (erfolgreiche) FTP-Verbindung mit der Box.

Die Tatsache, daß da das AVM-Recovery-Programm erst nachfragt, welchen Adapter Du verwenden willst (wenn es keinen mit einer statischen Adresse gibt), zeigt ja gleichzeitig an, daß es mehr als einen (aktivierten) Adapter gibt, den das Programm "auswählen" könnte. Und dann wundert es mich auch nicht wirklich, wenn EVA-Discover.ps1 vielleicht das falsche Interface benutzt. Schließlich gibt es dafür (obwohl die beste Lösung natürlich ein Rechner mit nur einem Interface wäre) auch noch den Parameter "if_address", damit die Broadcasts auf den richtigen Interface rausgehen.

Wobei es jetzt tatsächlich interessant wird, was die Ursache für die Boot-Loops angeht (auch wenn Du Dich besser an den LEDs als an der Erreichbarkeit des GUI orientieren solltest bei der Beurteilung, was die Box da gerade macht). Mir fällt einfach nicht wirklich irgendetwas Sinnvolles ein, was Du da "zerstört" haben könntest - ich will nur noch mal ganz sicher sein, daß wir nicht wieder aneinander "vorbeireden".

Nach dem Ende des Recovery-Programms endet erst einmal das dauerhafte Blinken der Power-LED und die geht für ein paar Sekunden (solange der Kernel initialisiert wird) dauerhaft an. Danach fängt die Info-LED hektisch an zu blinken (d.h. der Flashvorgang wird gestartet) und irgendwann hört die Info-LED wieder auf. Kurz danach blinken dann alle LEDs 1x kurz auf (wie beim "Strom ran") und es startet wieder das ca. 10 Sekunden-Blinken (nach ca. 3-5 Sekunden Dauerleuchten der Power-LED), während EVA auf eine FTP-Verbindung wartet. Danach geht die Power-LED wieder für längere Zeit an (erneut wird der Kernel geladen und das Root-FS gemountet) und was passiert dann genau? Die Länge des Intervalls zwischen zwei Starts gibt ja auch einen Hinweis darauf, wie weit die Initialisierung des Systems überhaupt kommt - da können ein paar zusätzliche Details kaum schaden.

Dein Starren auf das GUI und dessen Verfügbarkeit als Zeichen für "geht wieder" ist zwar verständlich, aber nicht unbedingt hilfreich beim Eingrenzen möglicher Probleme. Der "ctlmgr" und damit das GUI wird erst relativ spät gestartet und da könnte noch alles Mögliche vorher schiefgehen. Wenn alle Stränge reißen, müßte man sogar mal über die serielle Schnittstelle nachsehen, wo die Initialisierung am Ende klemmt - wobei ich mal davon ausgehe, daß die Box vor Deinen Aktionen 100% in Ordnung war und es sollte fast nicht möglich sein, den FPGA, den DECT-Controller oder die WLAN-Interfaces so weit zu beschädigen durch Schreibversuche über EVA, daß danach ein System tatsächlich "nicht mehr hochkommt" - auch wenn all diese Komponenten zuvor noch initialisiert werden (also vor dem GUI) und ein Fehler dabei die Box auch in Panik versetzt.

Aber man kann eben an den LEDs auch schon viel ablesen ... und auch ein "ping" hilft hier tatsächlich mal ausnahmsweise, weil zuerst die LAN-Schnittstellen initialisiert werden, wenn es an den Start des Netzwerks geht und man dann sowohl die IP-Adresse für die "lan"-Bridge "kennt" (bei einer Antwort und wenn das tatsächlich kein anderes Gerät ist, was diese sendet), als auch abschätzen kann, wie lange die Box nach dem Initialisieren der Ethernet-Schnittstellen "noch lebt".

Denn daß diese Schnittstellen beim Start des Systems erst mal nicht reagieren, hast Du ja weiter vorne auch schon bemerkt ... die ersten ICMP-Reply-Pakete nach dem Power-On kommen vom Bootloader und daß danach erst mal die Schnittstellen wieder "tot" sind, ist vollkommen normal - bis das startende FRITZ!OS die dann wieder initialisiert (sieht man sicherlich auch bei Dir am Switch mit passenden LEDs für dessen Ports).

Wenn man - anhand der Loop-Länge - eine Idee hat, was da "kaputt" sein könnte, kann man wieder versuchen, diese Funktionen in einer eigenen Firmware gezielt abzuschalten und zu testen, ob die Initialisierung dann durchläuft.

Da ich keine 7590 habe, habe ich auch kein passendes "Diagnose-Image" für eine solche ... mit so einem "selbstgestrickten" Image kann man auch hingehen und schon beim Start aus dem RAM (anstelle des Schreibens in den Flash) einiges an Daten (insbesondere das TFFS und die dort zu findenden Dateien "crash.log" und "panic.log", die Hinweise auf die Ursachen eines Neustarts enthalten) aus einer Box auslesen (die braucht man ohnehin für eine forensische Analyse) und über TFTP an ein anderes Gerät übertragen. Wie das aussehen könnte, kannst Du Dir in der Datei "/etc/init.d/E03-flash_update" der AVM-Firmware ansehen ... da wird (ziemlich am Ende) bei passender Parametrierung auch versucht, das Protokoll des Flash-Vorgangs an einen Protokoll-Server zu übertragen (ab Zeile 183 geht das los bei der 07.12). Das könnte also auch eine Alternative sein, daß man sich so ein Image zusammenbastelt und damit dann trotzdem noch an die Daten kommt, auch ohne das Gerät zu öffnen und die Serielle zu benutzen.

Es ist also auch noch nicht alles verloren ... nur scheint der "einfache Weg" tatsächlich verbaut. Was genau da nun defekt sein mag und wie man das durch einen falschen Flash-Versuch über EVA verursacht haben könnte (hier ist ja nicht der Bootloader defekt - hoffentlich jedenfalls, denn der existiert ja auch in zwei Kopien innerhalb der entsprechenden Partition und die Benutzung der zweiten sähe man m.W. nur über die serielle Konsole), will mir zwar im Moment nicht einleuchten, aber manchmal treten ja auch zwei Probleme gleichzeitig auf.

Irgendwelche EEPROMs in den verwendeten Komponenten (wie gesagt, würde ich hier zuerst auf den FPGA schauen und der hat m.W. gar keinen eigenen PROM - der DECT- und die WLAN-Chips haben jeweils eigene Speicherbereiche für einige Daten) sollten bei einem Schreibversuch über EVA auch nicht dran glauben müssen ... es bleibt also einigermaßen rätselhaft, was da jetzt "defekt" sein soll.

 

[Massa]

Uff, wieder viel (interessantes) Futter zu lesen.
Mal so zwischendurch: vielen Dank @PeterPawn für Deine Geduld mit mir und Deine Hilfsversuche...
EDIT: @JonDoe42: Dir natürlich auch vielen Dank für Deine Hilfsversuche

Wenn das AVM Recovery-Tool mich die Schnittstelle auswählen lässt, sind alle Schnittstellen des Systems auswählbar, also auch die deaktivierten (z.B. das TAP-Interface vom OpenVPN-Client).

Die LEDs reagieren bei mir nicht so, wie Du beschrieben hast.
Ich habe den Recovery-Vorgang jetzt nochmal durchgeführt, um die LEDs zu beobachten und habe hektisch mitgeschrieben - kann aber sein, dass es nicht 100% genau ist...
Nachdem das Recovery-Programm die folgenden Meldungen ausgegeben hat:

Lösche Flashbereich (mtd8)
Restauriere Flashbereich (mtd8)
Restauriere Flashbereich (mtd1)
FRITZ!Box 7590 erfolgreich wiederhergestellt!
Die Wiederherstellung ist nach einem Neustart des Gerätes abgeschlossen.

und den Button "Weiter>" freischaltet, reagieren die LEDs wie folgt:
Power/DSL ist erst dauerhaft an für ca. 10s, dann geht sie kurz aus und wieder an, dann blinkt sie im Sekundentakt.
Parallel zum Blinken geht die Fon/DECT-LED für ca. 2s an, dann blinkt diese immer zweimal kurz und ist dann für 1s aus und dann wieder doppelblinken.
Das geht für ca. 1min 50s so; während diese ganzen Vorgangs ist der Netzwerklink am Switch da und die Box reagiert auf den Ping zu 192.168.178.1
Dann gehen alle LEDs kurz für ca. 6s aus; ab jetzt ist kein Netzwerk-Link mehr vorhanden; und dann geht die Power/DSL-LED wieder dauerhaft an.
Weitere ca. 6s später geht diese kurz aus und dann wieder an, dann blinkt sie kurz und geht wieder an.

Etwa 30s später gehen alle LEDs ganz kurz an und wieder aus und dann geht wieder die Power LED an; der Netzwerk-Switch zeigt jetzt zwar einen Link, aber die Box ist nicht erreichbar per ping auf der 192.168.178.1
Das Spiel wiederholt sich ab jetzt etwa alle 30s... (Link weg, dann blinken alle LEDs kurz auf und wieder aus, Power-LED geht wieder an, irgendwann kommt der Link wieder, aber die Box ist nicht erreichbar...)

Achja, und vor der ganzen Aktion mit meinem falschen Flash-Kommando war die Box vollkommen lauffähig - habe sie zu dem Zeitpunkt per Web-Interface ansprechen können und der AVM Wizard lief los...

 

[PeterPawn]

Das irritiert mich jetzt mächtig. Ich habe extra noch einmal in das Handbuch der 7590 geschaut und da steht es genau so, wie es bei anderen FRITZ!Boxen auch der Fall ist (https://assets.avm.de/files/docs/fritzbox/fritzbox-7590/fritzbox-7590_man_de_DE.pdf - Seite 30) ... die Info-LED signalisiert einen laufenden Flash-Vorgang.

Wenn der hier gar nicht gestartet wird, muß ja irgendetwas zuvor das verhindern ... denn das Einschalten der LED (bzw. das Starten des Blinkens) erfolgt ziemlich am Beginn der "E03-flash_update", sowie feststeht, daß es etwas zu flashen gibt. Bis dahin sind nur die "S0X-irgendwas"-Skripte durchgelaufen - der "udevd" sollte nicht gestartet werden (weil da noch einmal derselbe Test wie in der "E03-flash_update" erfolgt und wenn geflasht werden soll, wird der Daemon gar nicht erst angetreten.

Die ersten 10 Sekunden mit Power-LED dauerhaft an, sind erwartbar und die von mir beschriebene Zeit, in der der Kernel entpackt und gestartet wird - irgendwo findest Du bestimmt auch ein Protokoll der seriellen Schnittstelle einer 7590 (oder die "dmesg"-Ausgabe aus einer Support-Datei) und da kann man in etwa sehen, was da zu welchem Zeitpunkt geschieht. Das Entpacken des Kernels braucht keine zwei Sekunden und dann startet seine Initialisierung. Die Power-LED fängt dann erst wieder an zu blinken, wenn (ca. 9-10 Sekunden, nachdem der Kernel die serielle Schnittstelle initialisiert hat und die Ausgaben dort starten) das AVM-LKM "led_module.ko" geladen wurde.

Und jetzt müßte sich zeitnah das Flashen anschließen ... was hier bei Dir offenbar nicht der Fall ist. Aus irgendeinem Grund bleibt das Flashen entweder hängen (und zwar VOR dem "update_led_on") oder wird gar nicht erst in Betracht gezogen und nach ca. 2:10 min startet dann offensichtlich der 120-Sekunden-Watchdog, der in "S05-watchdog" scharf gemacht wird (ca. 10 Sekunden nach dem Start des Kernels), die Box neu und zwar ohne daß irgendwie das System in den Flash geschrieben wurde. Die 1:50 min würde ich als "Schätzung" interpretieren und als "zu kurz" ansehen (oder ich habe das falsch zusammengerechnet aus #27) ... nach so langer Zeit kann eigentlich nichts anderes als der Watchdog zum Neustart führen und der wird eben auf 120 Sekunden gesetzt.

Die Aufteilung des NAND-Flashs kriegt der Linux-Kernel normalerweise vom Bootloader im FDT übermittelt, da sollte das erste Megabyte für den Urlader reserviert sein (von 0x0 bis 0x100000), danach die 4 MB für den TFFS-Speicher kommen (von 0x100000 bis 0x500000) und dann Platz für zwei Kernel a 8 MB reserviert sein (0x500000-0xD00000 und 0xD00000-0x1500000). Der Rest (491 MB) wird dann später als UBI-Device formatiert.

Wenn "led_module.ko" geladen werden kann (daher ändert sich ja das Blinken), wurde der Kernel entpackt, das Filesystem gemountet und "/sbin/init" gestartet. Auch der Neustart nach 120 Sekunden spricht dafür, daß der Watchdog korrekt aufgehetzt wurde.

=====================================================================

Ich sehe noch zwei Tests, die man vor dem Bestücken der seriellen Schnittstelle oder dem Erstellen eines "Diagnose-Images" machen könnte und der erste davon wäre die (einmalige) Umschaltung der Partitionen über "linux_fs_start". Und hier meine ich tatsächlich "einmalig", weil es nichts bringt, da wild hin und her zu wechseln. Die Installation beim Start aus dem RAM erfolgt normalerweise in die gerade aktiven Partitionen ... die Suche danach ist auch der Teil, der unmittelbar nach dem "update_led_on" folgen sollte.

Wenn man mal annimmt (ist aber nur eine "schwache Idee"), daß dabei dann die passenden Partitionen in "/proc/mtd" nicht gefunden werden (obwohl die eben aus dem FDT kommen sollten, zumindest die "raw MTD partitions" 0 bis 4 - die 4 ist dann der "Rest", der als UBI-Device verwendet werden soll) und daher das Setup fürs Flashen sofort wieder abbricht, dann wäre das "Fehlen" der Info-LED vielleicht auch noch zu erklären, weil es einfach zu schnell geht und die nicht einmal zum ersten Blinken kommt. Wobei ich auch nicht genau sagen kann, warum das jetzt beim anderen Partition-Set anders sein sollte - das Setup der Namen kommt für die Kernel-Partitionen ja aus dem FDT (mithin aus dem Bootloader) und für die Dateisystem-Partitionen aus der "drivers/mtd/avm/avm_mtd.c".

Wobei letztere sogar Vorkehrungen trifft, das UBI-Device "mtd4" erst einmal gar nicht zu mounten, wenn das "recovered=2" in "firmware_info" steht (was das AVM-Recovery-Programm ja setzen sollte, daher wollte ich ja, daß Du erst mal mit dem weitermachst, bis da irgendein System wieder läuft) und die gesamte MTD-Partition daher beim "E03-flash_update" neu initialisiert werden soll. Der Vorschlag mit dem anderen Wert von "linux_fs_start" ist also eher "nach Gefühl" und mehr "der Vollständigkeit halber", damit da nichts ausgelassen wird. Viel versprechen würde ich mir davon nicht ... wenn es erwartungsgemäß nichts bringt, würde ich "linux_fs_start" fest auf "0" setzen oder sogar ganz löschen (UNSETENV). Die Behandlung eines fehlenden Wertes als "0" sollte überall korrekt sein.

=====================================================================

Danach könntest Du noch ein Image bauen (aus dem originalen von AVM), wo Du die Datei aus dem Anhang hinzufügst unter "/etc/init.d/E01-send_logs" (ohne ".txt" und mit Ausführrechten, am besten 755). Wie das geht mit dem Entpacken, Ändern und erneutem Packen, habe ich irgendwo anhand von "telnet" für die 7580 gezeigt.

Wenn die Firmware diese Datei startet (was auch bei einem Laden ins RAM noch vor dem Flashen wäre, deshalb heißt die "E01..."), wird geprüft, ob "ptest" im Urlader-Environment sowohl einen Wert für "ipaddr" als auch "toaddr" enthält (wobei nicht auch "toaddr" geprüft wird, wenn das fehlt, wird einfach "192.168.178.10" angenommen, weil das bei AVM auch die Adresse des TFTP-Servers ist und noch an anderen Stellen diese Adresse verwendet wird in der Firmware) und wenn die gefunden werden, erstellt das Skript aus den im TFFS gespeicherten Daten vom letzten Absturz (crash.log) oder von der letzten Kernel-Panik (panic.log) eine kleine Textdatei (die enthält dasselbe, wie die Support-Datei am Ende, wenn solche Absturz-Protokolle existieren), die es danach per TFTP versucht auf den Server mit der Adresse "toaddr" zu schieben.

Allerdings wird das nur für ca. 10 Sekunden versucht, denn parallel läuft ja noch der 120-Sekunden-Watchdog mit und da darf man nicht zu sehr trödeln.

Das Format für "ptest" ist etwas gewöhnungsbedürftig, aber das ist von AVM übernommen. Mit der folgenden FTP-Session:

vidar:/home/GitHub/YourFritz/eva_tools $ ./eva_discover INTERFACE=vlan1 FROM=192.168.178.2 TO=192.168.178.1 BLIP=1;nc 192.168.178.1 21
EVA_FOUND=1
EVA_IP=192.168.178.1
220 ADAM2 FTP Server ready
USER adam2
331 Password required for adam2
PASS adam2
230 User adam2 successfully logged in
SETENV ptest ipaddr=178.11,toaddr=178.10
200 SETENV command successful
QUIT
221 Thank you for using the FTP service on ADAM2
221 Goodbye.
(Hier ggf. mit Ctrl-D die Eingabe beenden, wenn es nicht von alleine weitergeht.)
vidar:/home/GitHub/YourFritz/eva_tools $ eva_to_memory 7580.img.with.sendlog
Found AVM bootloader: AVM EVA Version 1.3229 0x0 0x46409
Found hardware revision: 225
Memory size is 0x08000000 (128 MB)
Memory size limited to 128 MB
Image size is 0x1944800 (25 MB)
Setting temporary memory size to: 0x066bb800
Setting temporary kernel args to: mtdram1=0x866bb800,0x88000000
Image uploaded to device.
vidar:/home/GitHub/YourFritz/eva_tools $ cat /srv/tftpboot/192.168.178.11-new.log
##### BEGIN SECTION CRASHLOG /proc/avm/log_sd
==========

BEGIN SECTION '/proc/avm/log_sd/crash'
----------
/proc/avm/log_sd/crash no data
----------
END SECTION '/proc/avm/log_sd/crash'

BEGIN SECTION '/proc/avm/log_sd/crash2'
----------
/proc/avm/log_sd/crash2 no data
----------
END SECTION '/proc/avm/log_sd/crash2'
==========
##### END SECTION CRASHLOG

##### BEGIN SECTION PANICLOG /proc/avm/log_sd
==========

BEGIN SECTION '/proc/avm/log_sd/panic'
----------
/proc/avm/log_sd/panic no data
----------
END SECTION '/proc/avm/log_sd/panic'

BEGIN SECTION '/proc/avm/log_sd/panic2'
----------
/proc/avm/log_sd/panic2 no data
----------
END SECTION '/proc/avm/log_sd/panic2'

==========
##### END SECTION PANICLOG
vidar:/home/GitHub/YourFritz/eva_tools $

würde das Skript also in der Box die 192.168.178.11 setzen und die Daten per TFTP an die 192.168.178.10 übertragen (das dauert natürlich etwas, aber nach 60 Sekunden oder so, sollte auch dem TFTP-Server etwas angekommen sein) ... auf dem Ziel-Host muß natürlich auch ein TFTP-Server laufen, der Schreibzugriffe akzeptiert und auch das Anlegen neuer Dateien (das sollte man am besten vorher schon mal testen, ehe man das Skript verdächtigt, seine Arbeit nicht richtig zu machen).

Als Ausgabedateiname wird die IP-Adresse der Box mit dem Zusatz "-new.log" verwendet. Bei meiner Demo gab es halt keine Absturzdaten ... die lassen sich auch nur einmal auslesen und danach sind sie weg. Aber bei einem Boot-Loop sollte es ja kein Problem sein, den nächsten Absturz herbeizuführen.

Bei Dir ist das sicherlich so, daß die Datei gar nicht "fest" in der Firmware landen wird, weil vermutlich ja schon der Flash-Vorgang nicht klappt - aber auch wenn man die in seinem eigenen Image haben sollte, schadet sie nichts ... solange "ptest" nicht gesetzt wird, bleibt das Skript ohne Auswirkungen ("ptest" wird von der Firmware bei erfolgreichem Start in "S42-ptest" selbst wieder geleert).

Das ist zwar noch kein vollwertiges "Diagnose-Image" (man kann ja auch den ganzen TFFS-Inhalt per TFTP aus der Box auslesen und ansonsten gar nichts weiter in dem Image machen, was irgendetwas am aktuellen Zustand der persistenten Speicher verändert), aber zum Auslesen der Log-Files reicht es üblicherweise ... weil ein System eigentlich immer bis zu diesem Punkt kommt, selbst wenn später irgendwelche Hardware (DECT, WLAN, Xilinx-FPGA, etc.) defekt sein sollte und die Box deshalb ins Koma (aka Boot-Loop) fällt.

Hat man dieses Skript in einem AVM-Image mit einer "E03-flash_update" und startet das FRITZ!OS aus dem RAM, wird natürlich danach noch der Flash-Vorgang starten ... wenn man schon weiß, daß der ohnehin scheitern wird, kann man auch noch ein "reboot" an das "E01-send_logs" dranhängen, damit danach gleich Ruhe ist (noch effektiver ist ein echo b > /proc/sysrq-trigger und der Flash-Speicher geschont wird.

Irgendwie mußt Du halt ermitteln, was genau das Flashen des neuen OS verhindert ... wenn Du ohnehin die serielle Schnittstelle benutzen willst, kannst Du Dir das mit dem Auslesen der Logs natürlich sparen. Das ist nur für eine "zerstörungsfreie Analyse" wichtig, wenn man die Box nicht öffnen kann oder will.

 

[Massa]

Das irritiert mich jetzt mächtig. Ich habe extra noch einmal in das Handbuch der 7590 geschaut und da steht es genau so, wie es bei anderen FRITZ!Boxen auch der Fall ist (https://assets.avm.de/files/docs/fritzbox/fritzbox-7590/fritzbox-7590_man_de_DE.pdf - Seite 30) ... die Info-LED signalisiert einen laufenden Flash-Vorgang.

Dann wird da bei mir wohl nicht geflasht

der erste davon wäre die (einmalige) Umschaltung der Partitionen über "linux_fs_start".

Das habe ich gemacht - hat (erwartungsgemäß) nichts verändert; gleiches Verhalten; "linux_fs_start" ist jetzt nicht mehr gesetzt...

Ich versuche jetzt ein Image zu basteln, das Dein angehängtes Script enthält (wobei mir noch nicht klar ist, wie das dann auf die Box kommen soll - wenn er doch anscheinend nicht wirklich flasht)
Nur um sicherzugehen - ich gehe nach diesem Thread vor: https://www.ip-phone-forum.de/threads/fritz-box-7580-firmware-153-06-90-telnet-service-freischalten-geht-auch-für-7560-und-7590.296678/
Ein wenig hat sich ja seitdem ja an Deinem git-Repository geändert.
Die Binärdateien sind jetzt als Submodule vorhanden; das habe ich noch ausgecheckt bekommen mit git submodule update --init --remote --force bin.
Ich bin mir jetzt aber nicht sicher, welche der unsquashfs - Binaries ich jetzt für das Auspacken der firmware.image verwenden soll: unsquashfs3-multi, unsquashfs4-be, oder unsquashfs4-le?
[EDIT] hab's jetzt einfach ausprobiert - nur das yf/bin/squashfs/x86_64/unsquashfs4-be kann was mit dem filesystem.image etwas anfangen...
...Ich mache dann mal weiter...
[EDIT2]: so, inzwischen habe das Image "eingepackt" und per eva-Tools an die Box geschickt (mit gleichem LED-Verhalten wie beim AVM-Recovery). Jetzt muss ich noch den tftp-Server aufsetzen um dann Deine o.a. Session nachstellen zu können - mache jetzt aber erst mal "Real-Life"-Pause ; melde mich hier wieder, wenn's was neues gibt

 

[PeterPawn]

wobei mir noch nicht klar ist, wie das dann auf die Box kommen soll - wenn er doch anscheinend nicht wirklich flasht

Deshalb läuft das ja vor dem Flashen ... auch beim Start aus dem RAM wird dieses Skript ausgeführt und so schreibt das Dir vor dem Versuch zu flashen, erst noch die zuletzt gesammelten Absturzdaten über TFTP raus - immer in der Hoffnung, daß da irgendetwas zu erkennen ist, woher das Boot-Loop kommt bzw. was da schiefgeht. EDIT: Wenn das System nicht bis zur "E01-send_log" kommt, stirbt es schon früher als angenommen ... dann muß man es ggf. weiter nach vorne schieben im Init-Ablauf.

Wenn Du parallel noch die "psupportd_sendmsg" löschst (die wird bevorzugt, wenn sie existiert und dann wird das "result file" von AVM mit diesem Programm an einen speziellen Server übertragen, anstatt TFTP zu benutzen in der "E03-flash_update") und die "E03-flash_update" so umschreibst, daß da parallel in einer Datei protokolliert wird (in der Funktion "print_message" einfach noch die Ausgabe in eine Datei schreiben), die Du dann bei Erfolg oder einem Fehler (in "print_error_log") über TFTP exportierst, brauchst Du die Werte bei "ptest" nur noch um ein "ver=xxx.yy.zz" zu ergänzen (sonst wird der Zweig nach dem Test von "fw_info_new" nicht abgearbeitet), um auch das Protokoll vom Flashen zu haben, ohne die serielle Schnittstelle zu bestücken.

Analog zu diesem Skript kann man ja noch weitere vor dem "E03-flash_update" einfügen, die ggf. die Ausgabe von eigenen Kommandos zur Diagnose per TFTP aus der Box schaffen (interessant wäre z.B. ein "cat /proc/mtd" zur Kontrolle der erkannten Partitionen oder ein "dmesg" für die bisher aufgelaufenen Kernel-Messages). Noch einfacher wäre sicherlich eine Shell oder "nc" ... nur ist die Zeit begrenzt, bis der Watchdog dei Box neu startet und "nc" ist in der AVM-BusyBox nicht enthalten. Außerdem muß eben irgendwer erst mal das Netzwerk konfigurieren, bevor man darüber auf eine Shell (z.B. per Telnet) zugreifen kann.

Da bleibt es einfacher und sicherer, wenn man die auszuführenden Kommandos erst einmal "skriptet" und sich hinterher die Ausgabe ansieht. Abgesehen davon beherrscht man nach dem dritten, vierten oder fünften Anlauf auch das Einpacken des SquashFS-Images und das Zusammenkopieren mit dem Kernel so weit aus dem Effeff, ebenso den Upload ins RAM, daß man sich Schritt für Schritt mit einem angepaßten Image weiter vortasten kann. Irgendwann kann man auch den Watchdog abschalten, wenn der einem auf die Ketten geht und man nicht fertig wird in den 120 Sekunden, die der vorgibt, wenn nichts anderes die Box neu startet.

Ich sag' jetzt einfach mal, daß Du Dir mit dem Zusammenbau eigener Images gerade das Rüstzeug zulegst, um künftig auch mit Freetz und dessen Images besser zurechtzukommen - auch wenn's wieder einfacher wird, sowie die Ursache für die derzeitigen Probleme erkannt und hoffentlich beseitigt wurde.

 

[Massa]

So, jetzt habe ich mal ein verändertes Image mit Deinem E01_send_logs hochgeladen.
Das scheint auch zu funktionieren, zumindest landet eine Log-Datei bei mir in /srv/tftp (habe ich angehängt).

Beim E03 scheint er schon nicht mehr anzukommen; zumindest landet keine weitere Datei im tftp-Verzeichnis...
Das von mir angepasste E03-Script habe ich ebenfalls angehängt...

EDIT: muss ich eigentlich das o.a. "setenv ptest" jedesmal machen oder ist das persistent zwischen Reboots bzw. Strom aus/an?

EDIT2: das hier im Log sieht komisch aus:

[    7.120000] UBI: attaching mtd4 to ubi0
[    7.756000] libphy: 0:05 - Link is Up - 1000/Full
[   10.300000] [0]system-load 100% loadavg 0.22 0.5 0.2 - 47 tasks:100 % curr:swapper/0(74 %) max:swapper/0(74 %, pid:1) pgstat: sum=106433 free=105100 slab=1333 alloc=368/s fault=0/s (sleep 0)
[   12.004000] NAND: Ecc Error Uncorrectable
[   12.008000] UBI warning: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read only 0 bytes, retry
[   12.016000] NAND: Ecc Error Uncorrectable
[   12.020000] UBI warning: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read only 0 bytes, retry
[   12.028000] NAND: Ecc Error Uncorrectable
[   12.036000] UBI warning: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read only 0 bytes, retry
[   12.044000] NAND: Ecc Error Uncorrectable
[   12.048000] UBI error: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read 0 bytes
[   12.056000] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.10.104 #1
[   12.064000] Stack : 00000006 00000000 00000000 00000000 00000000 00000000 80fc89ea 00000035
[   12.064000]    00000001 00000000 80c62d74 00000000 00000001 80cf880c 9fc64270 80da77db
[   12.064000]    80c62d74 00000000 00000001 80fc8190 80d2b410 ffffffb3 9ff9e000 8054de4c
[   12.064000]    00000006 8054abbc 00000000 00000000 80c6b128 9fc73c1c 9fc73c1c 9fc64270
[   12.064000]    00000000 00000000 00000000 00000000 00000000 00000000 00000000 9fc73b90
[   12.064000]    ...
[

Irgendwas scheint mit mtd4 kaputt zu sein?!

EDIT3: das hier kommt bei "cat /proc/mtd" (habe ich mal in Dein E01-Skript am Ende der get_logs-Funktion eingefügt):

dev:    size   erasesize  name
mtd0: 014ed000 00000200 "rootfs_ram"
mtd1: 00488a00 00000200 "kernel_ram"
mtd2: 00800000 00020000 "kernel"
mtd3: 00100000 00020000 "urlader"
mtd4: 00400000 00020000 "nand-tffs"
mtd5: 00800000 00020000 "reserved-kernel"
mtd6: 1eb00000 00020000 "ubi"

Das sieht mir jetzt so aus, als ob er die falsche Partition für's mounten des ubi-Devices nimmt?! Irgendwie ist die ganze Tabelle komisch! (enthält doppelte Einträge?)
Wie bekomme ich die denn korrigiert?

 

[PeterPawn]

Das sieht soweit eigentlich trotzdem einigermaßen gut aus.

Immerhin findet er das TFFS noch und initialisiert es passend:

[    4.756000] [TFFS3_CACHE_Configure] Setting up caching for backend nand
[    4.760000] [TFFS3-CACHE] Caching module for TFFS 3.x
[    4.768000] [TFFS3-NAND] NAND storage backend for TFFS 3.x
[    5.532000] [TFFS3-NAND] writing TFFS header to address 0x60000. SeqNr: 0x290d EraseCnt: 0xc
[    5.544000] [TFFS3-NAND] writing TFFS header to address 0xe0000. SeqNr: 0x290e EraseCnt: 0x4
[    5.552000] [TFFS3-NAND] Initialisation successful, 32/32/32 NAND blocks active, fill rate 13%
[    5.560000] TFFS: tiny flash file system driver. GPL (c) AVM Berlin (Version 3.0)
[    5.568000] Adam2 environment variables API installed.

Allerdings hat er Probleme beim Initialisieren des UBI-Devices für den Rest des Flash-Speichers:

[    6.796000] UBI: attaching mtd6 to ubi0
[   11.680000] NAND: Ecc Error Uncorrectable
[   11.684000] UBI warning: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read only 0 bytes, retry
[   11.692000] NAND: Ecc Error Uncorrectable
[   11.696000] UBI warning: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read only 0 bytes, retry
[   11.708000] NAND: Ecc Error Uncorrectable
[   11.712000] UBI warning: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read only 0 bytes, retry
[   11.720000] NAND: Ecc Error Uncorrectable
[   11.724000] UBI error: ubi_io_read: error -1 while reading 64 bytes from PEB 2333:0, read 0 bytes
[   11.732000] CPU: 2 PID: 1 Comm: swapper/0 Not tainted 3.10.104 #1
[   11.740000] Stack : 00000006 00000000 00000000 00000000 00000000 00000000 80fc89ea 00000035
[   11.740000]       00000001 00000000 80c62d74 00000002 00000001 80cf880c 9fc64270 80da77db
[   11.740000]       80c62d74 00000002 00000001 80fc8190 80d2b410 ffffffb3 9ffbf000 8054de4c
[   11.740000]       00000006 8054abbc 00000000 00000000 80c6b128 9fc73c1c 9fc73c1c 9fc64270
[   11.740000]       00000000 00000000 00000000 00000000 00000000 00000000 00000000 9fc73b90
[   11.740000]       ...
[   11.776000] Classified pointer on stack:
[   11.780000] 9fc64270 [task_struct(swapper/0): 9fc64060+0x210]
[   11.784000] 9ffbf000 [slab: type:kmalloc-4096 size:4096 start:0x9ffbf000+0x0]
[   11.792000] 8054abbc print_tainted+0xb0/0xcc
[   11.796000] 9fc73c1c [stack(swapper/0): 9fc70000+0x3c1c]
[   11.800000] 9fc73c1c [stack(swapper/0): 9fc70000+0x3c1c]
[   11.808000] 9fc73b90 [stack(swapper/0): 9fc70000+0x3b90]
[   11.812000] 8096b9e8 ubi_io_read+0x274/0x374
[   11.816000] Call Trace:
[   11.820000] 3b90: [<8052a53c>] 0x8052a53c show_stack+0x50/0x84
[   11.824000] 3c78: [<8096b9e8>] 0x8096b9e8 ubi_io_read+0x274/0x374
[   11.832000] 3cd8: [<8096bd88>] 0x8096bd88 ubi_io_read_ec_hdr+0x8c/0x224
[   11.836000] 3d10: [<80971528>] 0x80971528 scan_all.constprop.5+0xf8/0xb18
[   11.844000] 3d78: [<80972374>] 0x80972374 ubi_attach+0x148/0x170
[   11.848000] 3da0: [<80965804>] 0x80965804 ubi_attach_mtd_dev+0x65c/0xdcc
[   11.856000] 3e08: [<80f8e3bc>] 0x80f8e3bc ubi_init+0x2a8/0x3b8
[   11.864000] 3e68: [<80515060>] 0x80515060 do_one_initcall+0xf8/0x1a0
[   11.868000] 3ea0: [<80f71b98>] 0x80f71b98 kernel_init_freeable+0x164/0x234
[   11.876000] 3ef0: [<8050e5ac>] 0x8050e5ac kernel_init+0x18/0x180
[   11.880000] 3f10: [<80508550>] 0x80508550 ret_from_kernel_thread+0x10/0x18
[   11.888000]
[   11.892000] UBI error: ubi_attach_mtd_dev: failed to attach mtd6, error -1
[   11.896000] UBI error: ubi_init: cannot attach mtd6

Diesen Versuch der Initialisierung des UBI-Devices durch den Kernel (das Scannen sollte i.d.R. in weniger als zwei Sekunden durch sein) kann man nur umgehen, indem man in "firmware_info" noch den Zusatz "recovered=2" anhängt (oder auch einfach alles damit ersetzt, weil die Versionsnummer hier kein Schwein interessiert zu diesem Zeitpunkt) - das macht das AVM-Recovery-Programm normalerweise bei jedem neuen Schreiben eines TFFS-Images auch gleich mit. Die korrekte Behandlung dieses Umstands im Kernel (daß der also dann gar nicht erst versucht, die UBI-Partition zu aktivieren, wenn "recovered=2" gesetzt ist), sollte (mind.) seit 07.12 auch bei der 7590 vorhanden sein - andere 07.1x-Sources habe ich nicht und bei der 07.0x gab es diese "Ausnahmebehandlung" noch nicht, was dann ab und an zu Problemen führte, wenn der Kernel eben schon beim Versuch der UBI-Initialisierung (richtig) crasht, bevor das Flashen überhaupt die Chance hat, die Partition neu aufzubauen. Da ist also ein 07.1x-Kernel schon deutlich "robuster" als einer für 07.0x.

Du müßtest das in diesem Falle mal von Hand hinzufügen (und ja, die "ptest"-Variable wird bei JEDEM Start gelöscht und muß vor jedem Start aus dem Speicher neu gesetzt werden, wenn Du die Daten über "send_logs" "ausleiten" willst) - dann wird die UBI-Initialisierung im Kernel übergangen und später in der "E03-flash_update" nachgeholt, wo dann auch die Korrektur der gefundenen ECC-Fehler (bzw. das Ausblenden dieses PEB aus dem "Vorrat" der verfügbaren) erfolgen sollte, wenn es nicht am Ende soo viele ECC-Fehler im NAND-Flash gibt (auch nach dem Neuaufbau der UBI-Strukturen), daß die Initialisierung gar nicht durchkommt.

Wobei ich etwas irritiert bin ... wenn hier ECC-Fehler erkannt werden, kann das fast nur durch Hardware-ECC erfolgen und da fehlt mir wieder die Vergleichsmöglichkeit. Ich sehe bei meiner 7580 nur nach jedem Flashen eines neuen Systems, daß dann beim nächsten Start erst einmal die ECC-Berechnung über die neu geschriebene Partition startet ... vielleicht hat AVM da noch auf Software-ECC gesetzt. Irgendwo gab es auch mal ein Init-Skript, was da erst mal für die ECC-Berechnungen gesorgt hat ... wo genau das war und bei welcher Version, weiß ich nicht mehr.

Jedenfalls sollte die Neuinitialisierung der UBI-Partition (die hat hier die Nummer 6, weil es zusätzlich noch "kernel_ram" und "rootfs_ram" gibt, beim Start aus dem Flash hat sie i.d.R. die Nummer 4) auch in der Lage sein, einige ECC-Fehler wegzubügeln ... solange sie dafür nicht über Gebühr Zeit braucht, denn auch das muß natürlich alles innerhalb der 120 Sekunden erfolgen, die der Watchdog vorgibt. Jedenfalls setzt das System auch in Deinem Protokoll den Startvorgang fort und mountet das "rootfs_ram" als Wurzeldateisystem (mtdblock0, wie man an der Device-Nummer 31:0 sieht).

Das ist der zweite Punkt, der mich irritiert ... ich hätte eher erwartet, daß in der "panic.log" ein Protokoll des letzten Start-Versuchs aus dem Flash-Speicher stehen würde. Die einzige Erklärung, die mir hier einfiele, wäre es, daß Du diesen Start aus dem Flash nach dem vorhergehenden Fehler beim Start aus dem RAM noch verhindert hast (was durchaus richtig und begrüßenswert war, wenn es so wäre - nicht falsch verstehen, es ist nur nicht "das Erwartete" und deshalb schreibe ich das noch einmal auf, damit nicht auf beiden Seiten stillschweigend falsche Annahmen getroffen werden) und das System deshalb nicht dazu kam, die "panic.log" (bzw. den dafür reservierten Bereich in der TFFS-Partition) zu überschreiben.

Witzigerweise arbeitet dann aber die Box aus dem RAM-System weiter ... bis irgendwann der "telefon"-Daemon in einer CPU-Schleife landet (man sieht es an der Auslastung der CPU durch diesen) und dann die Box vom Watchdog nach 120 Sekunden neu gestartet wird.

===========================================================================================

Ich würde hier folgendes als nächstes versuchen ... erstens den Watchdog in der "S05-watchdog" deutlich verlängern oder sogar ganz rauswerfen, damit die UBI-Initialisierung nicht versehentlich durch den doch wieder abgebrochen wird. Da muß es irgendwo noch ein anderes Problem geben, denn die anderen Schritte (u.a. das "recovered=2" in "firmware_info") hat das AVM-Programm ja auch ausgeführt und trotzdem kam es nicht bis zur Installation des Systems.

Da fiele mir als naheliegende Erklärung wieder ein, daß die UBI-Initialisierung (u.a. wg. vieler Fehler) länger braucht (ich hatte das mal auf einer 7490 mit YAFFS (wobei das generell anders arbeitet und tatsächlich alle Blöcke der Reihe nach absucht), als es der Watchdog zuläßt ... wenn diese Annahme nicht stimmt, fiele mir nicht ein, was da zwischen E01-something und E03-something noch passieren könnte, was zumindest den Versuch der UBI-Initialisierung verhindert und schon der würde vom hektischen Blinken der Info-LED begleitet, weil Zeile 82 (in der originalen E03-flash_update von AVM) das anwerfen sollte, bevor die UBI-Partition neu aufgebaut wird. Wenn das bei Dir nicht geschieht, irritiert es mich aber auch (mal wieder) - der LED-Treiber ist jedenfalls geladen.

Deine E03-flash_update habe ich überflogen (damit bin ich beim "zweitens") ... wenn Du davon ausgehst, daß schon die "E01-send_logs" das Netzwerk initialisiert hat, bräuchtest Du natürlich das nicht mehr ausführen. Und ich erlaube mir mal noch einige andere Bemerkungen dazu ... ich würde z.B. "do_con_log_file" und alle Tests darauf komplett weglassen - das sind nur unnötige, zusätzliche Quellen für Syntax-Errors o.ä.; braucht eigentlich niemand.

Ansonsten würde ich (auch wenn ich das zuvor mißverständlich aufgeschrieben hatte) eher - ausgehend von der originalen Datei von AVM - alle Umleitungen von Ausgaben nach "/dev/console" oder "${tmp_log_file}" entfernen (auch in "print_message") und die gesamte Ausgabe des Skripts in eine Datei umlenken (ohne irgendwelche Faxen mit der Abfrage von zusätzlichen Variablen - wenn keine Serielle dranhängt, sieht ohnehin niemand die Ausgabe auf "/dev/console" zu diesem Zeitpunkt) - das geht z.B. aus dem laufenden Skript heraus mittels "exec" (siehe Shell-Dokumentationen, z.B. hier: https://tldp.org/LDP/abs/html/io-redirection.html - vorher irgendwo in Linux üben, wenn man das nicht täglich macht). Das hat parallel auch noch den Vorteil, daß man sich nicht durch einen Fehler bei der Verwendung von ">" bzw. ">>" (für "append") den bisher geschriebenen Inhalt entsorgen kann - weil man auf die Umleitungen bei den einzelnen Kommandos verzichten kann.

Diese Datei würde ich dann - ganz am Schluß bzw. innerhalb von "print_error_log", wobei da die letzte Zeile mit dem "cat" ohnehin raus kann - am Ende noch über TFTP zum Host senden (und mich ggf. darauf verlassen, daß das Netzwerk in E01-send_logs schon initialisiert wurde, wobei man die Adresse des TFTP-Servers aus "toaddr" in "ptest" ggf. noch auslesen müßte). Damit hast Du dann ein komplettes Protokoll des Flash-Vorgangs - egal wie der auch ausgehen mag. Die Zeilen 57 bis 81 aus dem Original von AVM (07.12) kannst Du auch problemlos löschen ... das wurde alles schon zuvor von anderen Skript-Dateien erledigt. Und wenn Du es ganz genau wissen willst, was der Flash-Vorgang an zusätzlichen Ausgaben im Kernel-Log erzeugt hat, schaffst Du am Ende von E03-flash_update auch noch die Ausgabe von "dmesg" aus der Box heraus über TFTP.

Wenn Du dann das Senden über TFTP obendrein noch im Rahmen einer "exit trap" machst (https://tldp.org/LDP/abs/html/debugging.html#EX76 - man kann da auch noch eine Funktion aufrufen und muß das nicht alles in einer Zeile behandeln), brauchst Du es auch nicht an verschiedenen Stellen einbauen - das wird dann bei Erfolg UND bei Fehlern aufgerufen. Leitet man noch STDERR auf STDOUT um (wenn STDOUT schon auf die Log-Datei verweist), kann man durch ein "set -x" auch zusätzlich das Protokollieren jedes einzelnen Shell-Kommandos anwerfen.

Ich will Dir damit nur ein paar Ideen geben, wie Du dem Problem weiter zu Leibe rücken könntest ... wenn aber auch das "ubiformat" nicht mit dem Flash klarkommt (wobei Du bei dessen Aufruf auch das "-q" streichen und ein "-v" stattdessen setzen solltest), fehlt mir die nächste Idee (zumindest im Moment).

Wichtig wäre nur, daß Du den zweiten Start der Box (nach dem, der aus dem RAM erfolgt) auch wieder abbrichst - damit beim nächsten Versuch die "panic.log"-Bereiche den Inhalt des letzten Starts aus dem RAM haben und nicht den, der beim Startversuch aus dem Flash neu geschrieben würde.

Auf alle Fälle muß Deine eigene E03-flash_update "wasserdicht" sein ... wenn die irgendwie abbricht wg. eines Syntax-Fehlers (Zeile 251/252 könnte einer sein), dann macht das System eben einfach weiter und es kommt nicht zum Neustart. Tatsächlich könntest Du Dir auch überlegen, alles "hinter" der E03-flash_update erst einmal rauszuwerfen, bis das Flashen in diesem Skript klappt ... nur ist es natürlich auch genau dieses System, was dann in den Flash geschrieben würde und dem fehlten dann die weiteren Skript-Dateien ebenso - insofern hat das Vorteile (einfacherer Ablauf mit "definiertem Halt") und Nachteile (wenn's erst mal geklappt hat, muß man es anschließend mit einem "richtigen System" wiederholen).

 

[Massa]

Das ist der zweite Punkt, der mich irritiert ... ich hätte eher erwartet, daß in der "panic.log" ein Protokoll des letzten Start-Versuchs aus dem Flash-Speicher stehen würde. Die einzige Erklärung, die mir hier einfiele, wäre es, daß Du diesen Start aus dem Flash nach dem vorhergehenden Fehler beim Start aus dem RAM noch verhindert hast (was durchaus richtig und begrüßenswert war, wenn es so wäre - nicht falsch verstehen, es ist nur nicht "das Erwartete" und deshalb schreibe ich das noch einmal auf, damit nicht auf beiden Seiten stillschweigend falsche Annahmen getroffen werden) und das System deshalb nicht dazu kam, die "panic.log" (bzw. den dafür reservierten Bereich in der TFFS-Partition) zu überschreiben.

Nein, ganz im Gegenteil. Ich habe die Box einfach (gefühlt) ewig lang weitermachen lassen...

Jetzt habe ich mal die "firmware_info" auf "recovered=2" gesetzt und ausserdem den Watchdog auf 5 min. erhöht.
Zudem habe ich die E01 ein klein wenig und die E03 in größerem Umfang geändert.
Trotz allem scheint er überhaupt nicht bei der E03 anzukommen - und das LED-Verhalten ist wie gehabt.

Wenn ich jetzt den Reboot durch den Watchdog verhindere und vorher den Stöpsel ziehe und erneut den ganzen Vorgang anstoße, landet zwar wie gewollt eine Log-Datei vom E01-Script im tftp-Verzeichnis (und nach wie vor keine vom E03-Script), die enthält aber keinerlei Logging vom Boot-Vorgang mehr -> also keine Panic-Einträge mehr.
Ich habe da auch mal ein dmesg eingebaut, damit man wenigstens ein bisschen was sieht...

Erst wenn ich ihn über den Watchdog rebooten lasse und dann erst den Stöpsel ziehe und dann wieder den gesamten Vorgang anstoße, steht wieder etwas in "/proc/avm/log_sd/panic".

Mit den Shellscript-Anpassungen war ich mir nicht sicher, was da AVMs Shell so für eine ist und ob die z.B. traps überhaupt unterstützt?!

Im Anhang habe ich jetzt mal meine aktuellen Inkarnationen der E01 und E03-Scripte angehängt - ebenso wie die geschriebenen Log-Dateien vom E01-Script.

 

[PeterPawn]

Erst wenn ich ihn über den Watchdog rebooten lasse und dann erst den Stöpsel ziehe und dann wieder den gesamten Vorgang anstoße, steht wieder etwas in "/proc/avm/log_sd/panic".

Solange der Watchdog nicht beißt, gibt es auch keine Panik - also auch kein Log dafür und die Daten in der "panic.log" sind immer die vom letzten(!) Absturz und nicht vom aktuellen Lauf des Systems. Die Ausgabe von "dmesg" in der S01-send_logs ist also noch deutlich zu früh, um ein Problem in der E03-flash_update zu erkennen.

Mit den Shellscript-Anpassungen war ich mir nicht sicher, was da AVMs Shell so für eine ist und ob die z.B. traps überhaupt unterstützt?!

Die Shell ist die "ash" der BusyBox und die unterstützt Traps (die sind ohnehin POSIX-Standard und selbst "dash" macht das richtig).

Was ich nicht verstehe ... die erste Ausgabe von "E01-send_logs" war DEFINITIV eine, wo das System aus dem RAM gestartet wurde - das sieht man schon daran, daß da eben die zwei Partitionen auf dem "ram_filesystem"-Device existieren. Das kann eigentlich nur geschehen, wenn man die Box zuvor (und zwar jedes Mal) über den Bootloader entsprechend präpariert. Wenn das System dann irgendwann neu startet und dabei aus dem Flash geladen wird, sollte es - sofern es tatsächlich abstürzt und nach Deiner Beschreibung gibt es ja ein Boot-Loop - bei einem Absturz auch eine neue "panic.log"-Datei produzieren (wobei das mit "Datei" nur ein Euphemismus ist, weil ich das jetzt nicht im Einzelnen erklären will, wie der TFFS-Treiber da arbeitet - den findet jeder Interessierte selbst in den Kernel-Quellen). Da frage ich mich dann schon, wie ein Protokoll von einem Start aus dem RAM da enthalten sein kann, wenn danach noch weitere Abstürze erfolgten.

Wenn die Protokoll-Datei von 10:50 Uhr einen Start mit "recovered=2" anzeigt, sieht man ja, daß die Initialisierung des UBI-Devices übergangen wurde - die Fehler im PEB 2333 sind darin nicht zu sehen, in dem Protokoll von dem Versuch, der mittels Watchdog abgebrochen wurde (das Protokoll stammt natürlich aus dem Start danach), sind sie aber immer noch vorhanden. Dieser Startversuch endet dann auch - erwartbar - mit einem fehlenden Root-Filesystem, weil das eben in einer Partition unterhalb des UBI-Devices stünde (da gibt es dann ja "kernel_ram" und "rootfs_ram" nicht, wie man am Ende des Panic-Logs sehen kann).

Was wissen wir bisher:

- Die Box kommt über die S0x-Skripte noch hinweg, denn die E01-send_logs funktioniert.
- Die Box führt das Flashen in E03-flash_update wohl nicht mehr aus.

Ich werde nur nicht so richtig schlau daraus, ob die E03-flash_update nun gar nicht erst aufgerufen wird oder ob sie abbricht (ggf. auch ohne das Log zu senden). Die "dmesg"-Ausgabe in der E01-send_logs macht keinen wirklichen Sinn (zumindest in diesem Kontext derzeit, wenn man daraus irgendwelche Fehler erkennen will) und so solltest Du sie (notfalls auch als Wiederholung) in ein Skript NACH der E03-flash_update packen.

Die Frage, die sich mir stellt, ist die, was denn nun beim "ubiformat" herauskommt - ich wage mal die These, daß das bisher noch nicht erfolgte ... ansonsten sollte der PEB 2333 entweder eine korrekte ECC-Summe haben oder nicht länger benutzt werden. Der Flash bei Deiner 7590 verwendet eine "erasesize" von 128 KB, d.h. es gibt insgesamt 4096 Blöcke, wobei 168 Blöcke für Urlader, TFFS und die Kernel-Partitionen verwendet werden und 3928 für das UBI-Device.

Irgendwie mußt Du die Box dazu kriegen, daß sie das "ubiformat" wenigstens mal anwirft und Dir dessen Ausgaben (zu -q und -v habe ich vorher schon etwas geschrieben) anzeigt. Selbst wenn da keine weiteren Volumes mit "ubimkvol" angelegt werden, sollte dann beim nächsten Anlauf aus dem RAM wenigstens das Flashen klappen (wenn "recovered=2" gesetzt ist und der Kernel das UBI-Device nicht weiter anfaßt). Im Moment dreht sich das irgendwie im Kreis ... wobei ich ja der Ansicht bin, daß die E03-flash_update durchaus aufgerufen wird, nur eben irgendwo ihre Probleme hat.

Notfalls mußt Du da eben eigene "Marker" einbauen - z.B. eignet sich das "led-ctrl" von AVM auch dafür, das kann man an dieser Stelle schon verwenden, weil das "led_module.ko" ja (erkennbar in den "dmesg"-Ausgaben) bereits geladen ist. Allerdings solltest Du nach dem Ein- oder Ausschalten irgendwelcher LEDs immer erst mal noch ein kurze "Gedenkpause" einlegen, damit man den Effekt des Kommandos auch verfolgen kann (wobei ein Handy-Video dabei natürlich noch mehr hilft, auch hinsichtlich der Dauer von Vorgängen und ihrer genauen Abfolge).

Da es zwischen E01-send_logs und E03-flash_update eigentlich keine weiteren Skripte geben sollte, KANN dazwischen eigentlich auch nichts abstürzen und so bleibt die Frage, warum er bei Dir in der E03-flash_update entweder nichts macht oder nichts ausgibt. Schon die Tatsache, daß er beim "update_led_on" ja nicht vorbeikommen soll (mach mal dahinter auch ein "sleep 3" oder so, damit man das Blinken wenigstens mal sieht, falls es danach von einem Fehler sofort wieder abgeschaltet wird), ist nur schwer zu erklären ... das Vorhandensein von "kernel_ram" und "rootfs_ram" ist ja "sicher", wie man in der Ausgabe von "cat /proc/mtd" in der E01-send_logs sieht.

Wobei Du Dir natürlich auch eine eigene BusyBox in das Image packen kannst und die kann dann wieder alles enthalten, was man für einen Shell-Zugriff über das Netzwerk benötigt (von "nc" bis zum "telnetd") - nur darf halt der Watchdog die Box nicht neu starten und das Netzwerk muß zuvor (wie in E01-send_logs bzw. im AVM-Code in E03-flash_update) konfiguriert werden. Wenn Du dann nach dem Start einer "remote shell" oder des Telnet-Daemons einfach nicht weitermachst mit dem Rest der Initialisierung (und das System nicht bis zum "telefon" und der CPU-Schleife kommt), kannst Du Dich damit wenigstens mal in der Box umsehen und die UBI-Kommandos notfalls auch mal "von Hand" absetzen. Die "Problemstelle" ist für meine Begriffe erst mal identifiziert (was nicht heißt, daß nicht weitere auftauchen können) - nun muß man sich überlegen, wie man darüber hinwegkommt und das ist das Neuformatieren des UBI-Devices.

 

[Massa]

Ich bin jetzt hergegangen und habe mir ein E02-Script gebastelt - das enthält jetzt Stück für Stück Teile aus dem E03-Script - nur um zu Schauen, wo es klemmt.

Ich habe sowohl in das E01-Script als auch ins E02-Script wildes Blinken über "/bin/update_led_on", entspr. sleeps und "/bin/update_led_off" eingebaut.
Nur tut sich an der Info-LED überhaupt nichts (obwohl lt. Prüfung in E02 das led_module geladen sein soll).
Aber immerhin läuft bisher mein E02-Script komplett durch und lädt brav sein Logging auf den tftp-Server; also sollte das mit dem trap-Handling etc. auch in E03 funktionieren...
...vom E03-Script fehlt aber weiterhin jedes Log auf dem tftp-Server...

Bei jedem Bootvorgang wurde jetzt SETENV ptest ipaddr=178.11,toaddr=128.10 sowie SETENV firmware_info recovered=2 eingegeben.

Werde erst morgen wieder weitermachen können - das nur so als Zwischenstand ;-)

EDIT: habe doch noch ein weiteres Stück angehängt - das ist jetzt E02-test_me_neu.txt und das Logging dazu ist E02_xxx-17-37.txt
Dort sieht man, dass das Problem beim ubiformat liegt - was das jetzt aber bedeutet / ob bzw. wie man das behebt, weiß ich nicht...

libscan: scanning eraseblock 2333libmtd: error!: cannot read 64 bytes from mtd6 (eraseblock 2333, offset 0)
        error 1 (Operation not permitted)
ubiformat: error!: failed to scan mtd6 (/dev/mtd6)

 

[PeterPawn]

Dann spiele doch mal etwas mit "led-ctrl" herum ... wenn am Ende nur die Info-LED nicht will (wobei das bei der 7590 mit dem Dimmen immer noch etwas anderes ist), wäre das ja ärgerlich. Da würde das Fehlen dieses Signals ja zu falschen Schlußfolgerungen verleiten, ob das System nun in E03-flash_update ist oder nicht.

Es gibt ein paar Aktionen für "led-ctrl", die man benutzen kann, um LEDs gezielt ein- und auszuschalten (das "update_led_{off,on}" macht auch nichts anderes, nur daß die Aktionen da "update_running" und "update_no_action" sind):

power_off -> Power-LED ausschalten (sonst sieht man i.d.R. nicht, ob sich etwas ändert bei weiteren Kommandos, weil das bei AVM als State-Machine realisiert ist)

update_led1 -> Info-LED einschalten
update_led1=0 -> Info-LED wieder ausschalten

update_led5 -> Power-LED einschalten
update_led5=0 -> Power-LED wieder ausschalten

Für andere LEDs gibt es weitere Kommandos (led-ctrl -l), nicht alle davon bewirken auch eine Änderung der Anzeige - auch klar, wenn z.B. zwei Aktionen dieselbe LED anschalten, muß man erst beide wieder "zurücknehmen" (wenn es keine gegenteilige Aktion gibt), damit die LED wieder aus ist.

Eine (ältere) Liste findet man z.B. hier: https://www.ip-phone-forum.de/threads/leds-ausschalten.266527/post-2004540 - die Aktionen oben sind auf einer 7580 getestet.

 

[Massa]

Ja, das mit den LEDs ist sicherlich für weitere Analysen richtig und wichtig - aber ich denke, es ist jetzt doch wichtiger, das Problem mit dem ubiformat zu lösen, oder nicht?
(oder deutet die Fehlermeldung auf einen Hardware-/Flashfehler hin? )

EDIT: was hat es denn mit diesem "erase counter" auf sich? Der hat bei den verschiedenen Blöcken unterschiedliche Werte - und den könnte man als Parameter für ubiformat angeben...
Ich habe zwar hier http://linux-mtd.infradead.org/faq/ubi.html#L_enable_ubi und hier http://linux-mtd.infradead.org/doc/ubi.html#L_flasher_algo gelesen - nur verstehe ich das nicht so richtig; das hat irgendwie mit dem Flash zu tun und gibt an, wie oft man das noch beschreiben/löschen kann?
Auf jeden Fall sollten doch "kaputte" Blöcke automatisch als "bad" markiert und dann ignoriert werden, oder nicht?

 

[PeterPawn]

Der Counter wird nur für das "wear leveling" benutzt und sollte nur in Ausnahmefällen beim "ubiformat" gezielt angegeben werden.

Das ist halt die Anzahl der Löschoperationen für diesen Block - davon verträgt Flash-Speicher nur eine begrenzte Anzahl (MLC-NAND noch am wenigsten) und daher versucht man, die Blöcke alle möglichst gleichmäßig zu benutzen und nicht einige durch ständiges Schreiben per se schon zu beschädigen.

Letztlich ist das auch die Idee hinter dem UBI-Konzept ... aus den physikalischen Blöcken (PEB) werden logische Blöcke (LEB) und anstatt die anhand ihrer fixen, physikalischen Adressen zu verwalten, werden die logischen Blöcke auf physikalische "gemappt" - d.h. wenn der LEB 1234 500x beschrieben wird, sorgt das "wear leveling" und das "logical volume mapping" dafür, daß das nicht wirklich immer derselbe physikalische Block ist (was dessen Lebensdauer stark einschränken würde), sondern daß da (im besten Falle) 500 verschiedene PEBs nur ein einziges Mal gelöscht und geschrieben werden.

Das mit den LEDs kann man ja quasi "nebenbei" gleich mit erledigen ... ich würde hier ohnehin mittlerweile auf eine "early shell" setzen (bzw. ich hätte schon längst die Serielle bestückt, aber das wohl auch eher deshalb, weil ich das früher oder später ohnehin bräuchte) und da kann man die paar Kommandos dann auch gleich mit testen.

 

[Massa]

Hmm, aber warum kommt da dann bei mir ein Lesefehler? Und wie kann ich den Fehler "fixen" / ignorieren?
Wenn man das ganze Prozedere mehrmals macht tritt der Fehler übrigens immer beim gleichen Block auf...

Wobei Du Dir natürlich auch eine eigene BusyBox in das Image packen kannst und die kann dann wieder alles enthalten, was man für einen Shell-Zugriff über das Netzwerk benötigt (von "nc" bis zum "telnetd") - nur darf halt der Watchdog die Box nicht neu starten und das Netzwerk muß zuvor (wie in E01-send_logs bzw. im AVM-Code in E03-flash_update) konfiguriert werden. Wenn Du dann nach dem Start einer "remote shell" oder des Telnet-Daemons einfach nicht weitermachst mit dem Rest der Initialisierung (und das System nicht bis zum "telefon" und der CPU-Schleife kommt), kannst Du Dich damit wenigstens mal in der Box umsehen und die UBI-Kommandos notfalls auch mal "von Hand" absetzen. Die "Problemstelle" ist für meine Begriffe erst mal identifiziert (was nicht heißt, daß nicht weitere auftauchen können) - nun muß man sich überlegen, wie man darüber hinwegkommt und das ist das Neuformatieren des UBI-Devices.

ich überlege gerade, wie ich wohl am einfachsten zu einem vollen Shellzugriff im Bootloader komme. Reicht es, den telnetd einfach zu starten /usr/sbin/telnetd -l /sbin/ar7login in einem Exx-Script?
Und klar, ich könnte mich dann "umsehen" - aber so richtig eine Idee, was ich dann mehr tun könnte, habe ich nicht - selbst wenn ich das ubiformat-Kommando von Hand absetze, wird es wohl immer noch fehlschlagen?!

EDIT:

(bzw. ich hätte schon längst die Serielle bestückt, aber das wohl auch eher deshalb, weil ich das früher oder später ohnehin bräuchte

Ohjee, im Löten / Hardware bin ich überhaupt kein Held - und da kann ich ja dann gleich noch mehr kaputt machen

 

[PeterPawn]

Hmm, aber warum kommt da dann bei mir ein Lesefehler?

Irgendwie fehlt mir ein Stück Film.

Ich kenne bisher folgende Ergebnisse:

- Beim Versuch, das UBI-Device im Kernel zu initialisieren, tritt in PEB 2333 ein ECC-Fehler auf (bzw. es sollen wohl nur die OOB-Daten gelesen werden für den Block). Das KANN halt passieren und im laufenden Betrieb (wenn das Device erst mal initialisiert ist), sollten solche Fehler auch korrekt behandelt werden, wenn nach dem Schreiben eines PEBs festgestellt wird, daß der Block beschädigt war - dann nimmt das System eben einen anderen und mappt den LEB dorthin.

- Übergeht man das Initialisieren des UBI-Devices im Kernel (mit "recovered=2" in "firmware_info" - und nur 2 ist hier wirksam, weder 1 noch 3:

198 /* called by the mtd driver whenever a new mtd device is being added */
199 void __init mtd_add_handler(struct mtd_info *mtd)
200 {
201
202     unsigned char *recover = NULL, *p = prom_getenv("firmware_info");
203
204         pr_debug("[%s] entered\n", __func__);
205
206     /*--------------------------------------------------------------------------------*\
207      * beim recover soll das UBI gelöscht und neu angelegt werden, also wird bei
208      * gesetzten recover nicht das UBI gemountet
209     \*--------------------------------------------------------------------------------*/
210     if (p) {
211         recover = strstr(p, "recovered=2");
212     }
213
214         if(mtd->type == MTD_UBIVOLUME) rename_ubi(mtd);
215
216         if(mtd_is_rootfs(mtd) && !prioritize_ram) {
217                 prioritize_ram = mtd_is_ram(mtd);
218                 announce_root(mtd);
219         } else if(!strcmp(mtd->name, "urlader")) {
220                 urlader_mtd = mtd;
221                 pr_debug("[%s] mtd%d[%s] set urlader_mtd", __func__, mtd->index,
222                          mtd->name);
223 #if defined(CONFIG_TFFS)
224         } else if(!strcmp(mtd->name, "nand-tffs")) {
225                 TFFS3_Register_NAND(mtd);
226                 pr_debug("[%s] tffs3 on MTD %s\n", __func__, mtd->name);
227 #endif
228         } else if(!strcmp(mtd->name, "ubi")) {
229         if ( ! recover) {
230             ubi_mtd_param_parse(mtd->name, NULL);
231             pr_debug("[%s] UBI on MTD %s\n", __func__, mtd->name);
232         } else {
233             pr_debug(KERN_ERR "{%s} box recovered - %s\n", __func__, recover);
234         }
235         } else {
236                 pr_debug("[%s] mtd \"%s\" is not handled by me.\n", __func__,
237                          mtd->name);
238         }
239 }

- aus drivers/mtd/avm/avm_mtd.c),
so wird (logischerweise) der Fehler in PEB 2333 auch nicht bemerkt vom Kernel. Hier müßte jetzt das "ubiformat" aus der E03-flash_update das Device neu initialisieren ... warum es das bei Dir nicht macht, ist bisher vollkommen unklar. Solltest Du das mittlerweile herausbekommen haben, fehlt hier m.E. das dazu passende Protokoll - oder ich habe das überlesen, dann wüßte ich gerne, wo das wäre.

Der Fehler in PEB 2333 sollte beim Formatieren des UBI-Devices entweder "verschwinden" oder der Block wird dann eben als "defekt" aussortiert und nicht weiter verwendet. So ein ECC-Error kann ja auch nur an einem Bit-Flip liegen und der gesamte Block ist gar nicht wirklich defekt. Ich habe keine Ahnung, wieviele Ein-Bit-Fehler der verwendete ECC--Algorithmus korrigieren kann, wenn überhaupt ... oft redet man heute ja schon von "ECC" (was eigentlich ein "Error Correction Code" war), wenn die Datenintegrität mit irgendwelchen Prüfsummen überwacht wird und nicht mal die Korrektur von einzelnen Bits möglich ist.

Andererseits sind ein paar defekte Blöcke in einem NAND-Flash auch nichts Ungewöhnliches ... meine 7580 hat im Moment vier davon in dem Bereich, der vom UBI-Layer verwaltet wird:

# ubinfo -d 0
ubi0
Volumes count:                           4
Logical eraseblock size:                 258048 bytes, 252.0 KiB
Total amount of logical eraseblocks:     1960 (505774080 bytes, 482.3 MiB)
Amount of available logical eraseblocks: 0 (0 bytes)
Maximum count of volumes                 128
Count of bad physical eraseblocks:       4
Count of reserved physical eraseblocks:  36
Current maximum erase counter value:     383
Minimum input/output unit size:          4096 bytes
Character device major/minor:            246:0
Present volumes:                         0, 1, 2, 3
#

Ich verstehe also nicht wirklich, was Du anderes machen willst, um den ECC-Fehler "zu fixen", als dieses MTD für den UBI-Layer neu zu formatieren ... dabei würde das ja automatisch "gefixt". Wenn das "ubiformat" hingegen nicht funktionieren sollte, wäre ein Protokoll davon mit konkreten Fehlermeldungen (daher ja auch der Hinweis, daß man "-q" rauswerfen und "-v" hinzufügen sollte beim Aufruf) schon ziemlich hilfreich ... das heißt zwar noch nicht, daß man damit dann auch eine Lösung finden muß, aber zumindest hat man dann eine Idee, was da beim "ubiformat" wohl schiefgeht. Bisher weißt Du ja noch nicht einmal (zumindest nach dem, was man hier bisher lesen konnte), ob das System überhaupt bis zum "ubiformat" in der E03-flash_update kommt oder nicht.

Das Überspringen der UBI-Initialisierung im Kernel bei "recovered=2" sorgt auch nur dafür, daß das System da nicht direkt wg. falscher Strukturen in Panik verfallen kann - das "Aushängen" des UBI-Devices (also das Abmelden des MTD beim UBI-Layer) übernimmt ansonsten das "ubidetach" ... natürlich kann/darf/soll man die UBI-Strukturen nicht neu initialisieren (aka "formatieren"), wenn das Device aktiv ist. Wenn man das "ubiformat" also von Hand machen wollte und das MTD ist beim UBI-Layer angemeldet (was entweder der Kernel macht, wenn kein "recovered=2" gesetzt ist oder ein "ubiattach" übernimmt), dann muß man das vorher erst noch beim UBI-Layer abmelden mit dem "ubidetach".