[gelöst] DM8000 hängt in Bootschleife (kann nicht fernsehen)

[CO_Windler]

Dies ist ein Notfall. Ich kann nicht mehr fernsehen. Meine Dreambox DM8000 (läuft per SCART über VHS-Rekorder an Toshiba Koffer-TV mit PAL-Bildröhre, Empfang per Kabel, OpenATV 6.1) blieb gestern beim Runterfahren hängen. Als ich sie heute bootete, kam das Ladebild (OPEN ATV, dann OPEN ATV 6.1), was wie üblich einige Male das Bildformat (16:9, 4:3 etc. mit blau rotierendem Spinner) umschaltet und im Display der gelbe Ladebalken. Danach geht kurz die LAN-Verbindung zum PC (Linux Mint). Doch dann flackert das "OpenATV 6.1" Ladebild mit Spinner nun einige Male und hängt in einer Schleife, die zwischen 4:3 und 16:9 umschaltet. Per Ethernet ist sie danach nicht mehr erreichbar. Sie lässt sich nur per Netzschalter ausschalten, bootet dann genauso.

Kann es sein dass irgendein Speicher übergelaufen ist? (EPG etc. schreibt sie AFAIK auf die 16GB CF-Karte. Filme sind auf interner 1.4GB Festplatte.) Oder kann das an Netzteil-Elkos oder defektert Lithiumbatterie liegen? Welche Dateien schreibt die Dreambox (OpenATV 6.1) beim Runterfahren, die den Neustart verhindern? (Kann z.B. fehlerhafter EPG-Inhalt sowas bewirken?) Während ich per LAN auf die Box komme, sieht per FTP und rlogin das Dateisystem intakt aus und nichts zu voll.

Code: Alles auswählen

root@dreambox:~# df -a -h
Filesystem                Size      Used Available Use% Mounted on
ubi0:rootfs             224.5M    129.1M     95.4M  58% /
devtmpfs                 72.9M      4.0K     72.9M   0% /dev
proc                         0         0         0   0% /proc
sysfs                        0         0         0   0% /sys
tmpfs                    64.0K         0     64.0K   0% /media
tmpfs                    73.0M    132.0K     72.9M   0% /var/volatile
/dev/mtdblock2            7.0M      3.8M      3.2M  54% /boot
/dev/sdb                 14.9G    515.6M     14.4G   3% /media/sdb
/dev/sde1                 1.4T      1.1T    281.4G  80% /media/hdd
devpts                       0         0         0   0% /dev/pts
/etc/auto.network            0         0         0   0% /media/autofs

In /var/log finde ich die Logdatei messages, die während des Boovorgangs wächst bis irgendwann die LAN-Verbindung abbricht. Die geht dann etwa bis hier.

/var/log/messages

Code: Alles auswählen

Nov 25 08:07:57 dreambox syslog.info syslogd started: BusyBox v1.24.1
Nov 25 08:07:57 dreambox user.notice kernel: klogd started: BusyBox v1.24.1 (2018-04-24 14:13:01 CEST)
Nov 25 08:07:57 dreambox user.info kernel: 06 Red Hat, Inc.
(...)
Nov 25 16:52:31 dreambox user.warn kernel: [  124.324000] using 50.00Hz as MonitorRefreshRate
Nov 25 16:52:31 dreambox user.warn kernel: [  124.444000] SET FORMAT: display[0], format=7
Nov 25 16:52:31 dreambox user.warn kernel: [  124.448000] bcm_video_analog_port_setup (fmt=7)
Nov 25 16:52:32 dreambox user.warn kernel: [  124.584000] SET FORMAT: display[1], format=7
Nov 25 16:52:32 dreambox user.warn kernel: [  124.703000] set current avs auto aspect to 4:3
Nov 25 16:52:32 dreambox user.warn kernel: [  124.708000] disable wss on display 0
Nov 25 16:52:32 dreambox user.warn kernel: [  124.712000] disable wss on display 1
Nov 25 16:52:32 dreambox user.warn kernel: [  124.718000] set sb to 3(2)
Nov 25 16:52:50 dreambox user.warn kernel: [  142.648000] enigma2 invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=-14, oom_score_adj=-999
Nov 25 16:52:50 dreambox user.warn kernel: [  142.657000] Call Trace:
Nov 25 16:52:50 dreambox user.warn kernel: [  142.659000] [<80491af8>] dump_stack+0x8/0x34
Nov 25 16:52:50 dreambox user.warn kernel: [  142.664000] [<80084c48>] dump_header.isra.4+0x84/0x1a0
Nov 25 16:52:50 dreambox user.warn kernel: [  142.669000] [<80084f98>] oom_kill_process.isra.9+0xb4/0x2b8
Nov 25 16:52:50 dreambox user.warn kernel: [  142.675000] [<800855e8>] out_of_memory+0x230/0x398
Nov 25 16:52:50 dreambox user.warn kernel: [  142.679000] [<80088d3c>] __alloc_pages_nodemask+0x6c4/0x6d8
Nov 25 16:52:50 dreambox user.warn kernel: [  142.685000] [<800834e4>] filemap_fault+0x240/0x4d8
Nov 25 16:52:50 dreambox user.warn kernel: [  142.690000] [<8009e8d4>] __do_fault+0x8c/0x4d8
Nov 25 16:52:50 dreambox user.warn kernel: [  142.694000] [<800a1d1c>] handle_pte_fault+0x9c/0x870
Nov 25 16:52:50 dreambox user.warn kernel: [  142.699000] [<800a2580>] handle_mm_fault+0x90/0xe8
Nov 25 16:52:50 dreambox user.warn kernel: [  142.704000] [<8000e788>] do_page_fault+0xb8/0x390
Nov 25 16:52:50 dreambox user.warn kernel: [  142.709000] [<80004600>] ret_from_exception+0x0/0x28
Nov 25 16:52:50 dreambox user.warn kernel: [  142.714000]
Nov 25 16:52:50 dreambox user.warn kernel: [  142.716000] Mem-Info:
Nov 25 16:52:50 dreambox user.warn kernel: [  142.718000] Normal per-cpu:
Nov 25 16:52:50 dreambox user.warn kernel: [  142.721000] CPU    0: hi:   90, btch:  15 usd:  34
Nov 25 16:52:50 dreambox user.warn kernel: [  142.726000] CPU    1: hi:   90, btch:  15 usd:   0
Nov 25 16:52:50 dreambox user.warn kernel: [  142.730000] active_anon:29532 inactive_anon:33 isolated_anon:0
Nov 25 16:52:50 dreambox user.warn kernel: [  142.730000]  active_file:50 inactive_file:51 isolated_file:0
Nov 25 16:52:50 dreambox user.warn kernel: [  142.730000]  unevictable:0 dirty:0 writeback:0 unstable:0
Nov 25 16:52:50 dreambox user.warn kernel: [  142.731000]  free:2048 slab_reclaimable:703 slab_unreclaimable:2179
Nov 25 16:52:50 dreambox user.warn kernel: [  142.731000]  mapped:6 shmem:34 pagetables:127 bounce:0
Nov 25 16:52:50 dreambox user.warn kernel: [  142.759000] Normal free:8192kB min:8192kB low:10240kB high:12288kB active_anon:118128kB inactive_anon:132kB active_file:200kB inactive_file:204kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:260096kB mlocked
Nov 25 16:52:50 dreambox user.warn kernel: [  142.799000] lowmem_reserve[]: 0 0
Nov 25 16:52:50 dreambox user.warn kernel: [  142.802000] Normal: 58*4kB 37*8kB 18*16kB 9*32kB 1*64kB 1*128kB 1*256kB 1*512kB 0*1024kB 1*2048kB 1*4096kB = 8208kB
Nov 25 16:52:50 dreambox user.warn kernel: [  142.813000

Ich habe im Netzteil einige neben Kühlkörpern sitzende Mini-Elkos ausgetauscht (i.a. sterben diese und nicht die großen); nur einer war mit <300 statt 330uF etwas daneben, aber laut AVR-Transistortester hielten sich Innenwiderstand noch in Grenzen. Die eingelötete 3V-Knopfzelle hält noch immer 3V Spannung =>nicht ersetzt. Immerhin konnte ich meine 2. grüne Power-LED nachlöten (Taster leuchtete nur noch halb). Habe dann versucht die Box mit entnommenen Tunern, DVD-Laufwerk und CF-Karte zu starten, was nichts ändert. Interessant ist dass sie nach Herunterfahren per Affengriff (Up+Down+Power) sich doch noch per Fernbedienung einschalten lässt.

Code: Alles auswählen

root@dreambox:~# init 4; sleep 5; killall -9 enigma2

Wenn ich hiermit per rlogin enigma2 beende, crasht die LAN-Verbindung nicht mehr, sodass ich beliebig lange das Filesystem untersuchen und Dateien kopieren kann. Wenn ich enigma2 dann manuell wieder starte, macht es im Terminal jede Menge Meldungen (findet manche Dateinamen nicht? Hier sind einige Errors), doch am Ende killt es sich offenbar selbst.

Code: Alles auswählen

root@dreambox:~# enigma2
[eErrorOutput] PIPE_BUF: 4096
[eErrorOutput] F_SETPIPE_SZ: 1048576
[eErrorOutput] F_GETPIPE_SZ 0: 1048576
PYTHONPATH: /usr/lib/enigma2/python
DVB_API_VERSION 5 DVB_API_VERSION_MINOR 4
(...)
05:37:07.3536 Components/Language.py:89 activateLanguage  Activating language Deutsch
05:37:08.9770 skin.py:66 addSkin  [SKIN ERROR] attempt to add a skin without filename
05:37:08.9815 skin.py:196 <module>  [SKIN] loading user defined colors for skin MetrixHD/skin.MySkin.xml/skin_user_colors.xml                                                                           
05:37:08.9827 skin.py:202 <module>  [SKIN] loading user defined header file for skin MetrixHD/skin.MySkin.xml/skin_user_header.xml
(...)
05:37:13.1644 Components/AVSwitch.py:157 readPreferredModes  [AVSwitch] reading edid modes failed, using all modes                                                                                      
05:37:13.1657 Components/AVSwitch.py:163 readPreferredModes  [AVSwitch] reading _preferred modes:  ['']                                                                                                 
05:37:13.1666 Components/AVSwitch.py:172 readPreferredModes  [AVSwitch] preferend modes not ok, possible driver failer, len= 1                                                                          
05:37:13.2421 RecordTimer.py:36 <module>  [RecordTimer] import from 'Screens.InfoBar import InfoBar' failed: cannot import name InfoBar                                                                 
(...)
05:37:29.4752 Components/InputDevice.py:64 getInputDeviceType  Unknown device type: dreambox front panel                                                                                                
05:37:29.6665 Components/AVSwitch.py:379 setAspect  [AVSwitch] setting aspect: 4:3
05:37:29.6839 Components/AVSwitch.py:393 setWss  [AVSwitch] setting wss: auto(4:3_off)              
05:37:29.6933 Components/AVSwitch.py:399 setPolicy43  [AVSwitch] setting policy: panscan            
05:37:29.7119 Components/AVSwitch.py:416 setPolicy169  [AVSwitch] setting policy2: letterbox        
05:37:29.7744 Components/AVSwitch.py:157 readPreferredModes  [AVSwitch] reading edid modes failed, using all modes                                                                                      
05:37:29.7765 Components/AVSwitch.py:163 readPreferredModes  [AVSwitch] reading _preferred modes:  ['']                                                                                                 
05:37:29.7775 Components/AVSwitch.py:172 readPreferredModes  [AVSwitch] preferend modes not ok, possible driver failer, len= 1    
(...)
05:37:51.1393 Components/PluginComponent.py:56 readPluginList  Plugin  Extensions/WebInterface failed to load: No module named plugin
(...)

das Ende lautet

Code: Alles auswählen

05:18:06.7631 Plugins/Extensions/AutoTimer/AutoPoller.py:19 __init__  [AutoTimer] Auto Poll Enabled
05:18:06.7767 Plugins/Extensions/Infopanel/SwapManager.py:25 SwapAutostart  [SwapManager] autostart
05:18:06.7778 base/console.cpp:110 execute [eConsoleAppContainer] Starting /bin/sh
05:18:06.8043 Plugins/SystemPlugins/CommonInterfaceAssignment/plugin.py:630 autostart  [CI_Assignment] activating ci configs:
Killed

Was hier enigma2 abschießt ist unklar. Jedenfalls flackert und ruckelt der TV-Bildschirm dabei viel weniger als beim normalen Start und auch die LAN-Verbindung bleibt bestehen. Ich habe den Verdacht, dass evt. durch Timeouts irgendein Script per Schleife versucht enigma2 mehrmals gleichzeitig auszuführen, wodurch sich die I/O völlig verheddert.

[CO_Windler]

Sie lebt! Ich habe in /etc/enigma2 grade eine recht monströse Datei timers.xml von 27.5MB gefunden, die zum Großteil aus folgender Endlosschleife besteht:
[code}<log code="8" time="1732485700">freeing a tuner failed</log>
<log code="1" time="1732485700">&apos;get best playable service for group... record&apos; failed</log>
<log code="7" time="1732485700">prepare failed</log>
<log code="1" time="1732485700">&apos;get best playable service for group... record&apos; failed</log>
<log code="7" time="1732485700">prepare failed</log>
<log code="1" time="1732485700">&apos;get best playable service for group... record&apos; failed</log>
<log code="7" time="1732485700">prepare failed</log>
<log code="1" time="1732485700">&apos;get best playable service for group... record&apos; failed</log>
<log code="7" time="1732485700">prepare failed</log>
...[/code]
Dieser Datenmüll überlastete offenbar irgendeinen Echtzeit-Prozess oder müllte Speicher so voll, dass enigma2 sich selbst terminierte. Nach Löschen von timers.xml startet die Box wieder. Sie legt für eine einzelne Aufnahme dort nur etwa 431 Bytes ab.

Ich hatte schon öfter Probleme beim Markieren von Aufnahmezeiten im EPG, die manchmal der vorigen oder folgenden Sendung zugeordnet werden. Und wenn 2 Aufnahmen gleichzeitig einen Tuner anfordern (oft z.B. Vox und ZDF), hängt sich die Box regelmäßig komplett auf und lässt sich nur per Netzschalter (manchmal auch Affengriff Up+Down+Power) neu starten. Dabei ändert sich die Aufnahme oft auf den obersten Sender der "Alle" Kanalliste "1+1 Internationall", der irgendwelche griechischen(?) Schriftzeichen anzeigt. Zudem schaltet die Box bei gleichzeitiger Timeraufnahme auf 2 Tunern meist die Kanalliste von Favoriten auf "Alle" um, was beim Sender wählen verwirrt, da man aus der alphabetischen riesigen Liste erstmal mit OK und Blau zurück auf Favoriten wechseln muss.