NEWS
[Problem] ioBroker stürzt ab - Zugriff auf admin
-
Hallo zusammen,
ioBroker läuft bei mir auf einem Raspberry 3.
Immer wieder stürzt mein ioBroker ab. D.h. ich habe keinen Zugriff mehr auf ioBroker und den Raspi selbst. Es ist dann kein Zugriff auf Weboberfläche, kein Zugriff via Putty möglich. Abhilfe schafft nur Versorgungspannung AUS-EIN. Dann startet ioBroker und ich habe ohne Probleme Zugriff.
Mir ist aufgefallen, dass die meisten Abstürze dann auftreten, wenn ich via Weboberfläche auf die Admin-Oberfläche zugreife. Die Oberfläche erscheint noch (kurz), dann sieht man aber die drehenden Kreise und der Raspbi ist (scheinbar) abgestürzt.
Das ioBroker-Log-File sieht so aus. Man sieht hier den Zeitpunkt kurz vor dem Absturz und den Boot:
018-09-02 16:21:01.208 - error: cloud.0 Ping timeout 2018-09-02 15:17:18.742 - info: host.ioBroker-RasPi iobroker.js-controller version 1.4.2 js-controller starting 2018-09-02 15:17:18.758 - info: host.ioBroker-RasPi Copyright (c) 2014-2018 bluefox, 2014 hobbyquaker 2018-09-02 15:17:18.759 - info: host.ioBroker-RasPi hostname: ioBroker-RasPi, node: v8.11.3 2018-09-02 15:17:18.768 - info: host.ioBroker-RasPi ip addresses: 192.168.178.120 2018-09-02 15:17:20.175 - info: host.ioBroker-RasPi inMem-objects listening on port 9001 2018-09-02 15:17:20.225 - info: host.ioBroker-RasPi InMemoryDB connected 2018-09-02 15:17:20.301 - info: host.ioBroker-RasPi 58 instances found 2018-09-02 15:17:20.522 - info: host.ioBroker-RasPi starting 41 instances 2018-09-02 16:23:17.686 - info: host.ioBroker-RasPi instance system.adapter.admin.0 started with pid 835 2018-09-02 16:23:17.946 - info: host.ioBroker-RasPi States connected to redis: 127.0.0.1:6379 2018-09-02 16:23:21.567 - info: host.ioBroker-RasPi instance system.adapter.web.0 started with pid 842 2018-09-02 16:23:24.152 - info: admin.0 States connected to redis: 127.0.0.1:6379 2018-09-02 16:23:24.509 - error: admin.0 setObject id missing!! 2018-09-02 16:23:24.530 - info: admin.0 starting. Version 3.5.6 in /opt/iobroker/node_modules/iobroker.admin, node: v8.11.3 2018-09-02 16:23:24.584 - info: admin.0 requesting all states 2018-09-02 16:23:24.590 - info: admin.0 requesting all objects 2018-09-02 16:23:24.594 - info: admin.0 Request actual repository... 2018-09-02 16:23:26.668 - info: web.0 States connected to redis: 127.0.0.1:6379 2018-09-02 16:23:27.267 - info: admin.0 received all states 2018-09-02 16:23:27.332 - error: web.0 setObject id missing!! 2018-09-02 16:23:27.353 - info: web.0 starting. Version 2.4.1 in /opt/iobroker/node_modules/iobroker.web, node: v8.11.3 2018-09-02 16:23:28.804 - info: web.0 socket.io server listening on port 8082 2018-09-02 16:23:28.813 - info: web.0 http server listening on port 8082 2018-09-02 16:23:29.208 - info: vis.0 States connected to redis: 127.0.0.1:6379 2018-09-02 16:23:29.473 - info: vis.0 starting. Version 1.1.7 in /opt/iobroker/node_modules/iobroker.vis, node: v8.11.3 2018-09-02 16:23:29.550 - info: host.ioBroker-RasPi instance system.adapter.history.0 started with pid 896 2018-09-02 16:23:29.829 - info: vis.0 vis license is OK. 2018-09-02 16:23:31.970 - info: admin.0 received all objects 2018-09-02 16:23:32.077 - info: history.0 States connected to redis: 127.0.0.1:6379 2018-09-02 16:23:32.312 - info: history.0 starting. Version 1.8.5 in /opt/iobroker/node_
Die Zeitverschiebung ist vermutlich darauf zurückzuführen, dass der Raspbi sich während des Boots die aktuelle Zeit holt.
Man sieht das der Cloud-Service vor dem Absturz nicht erreichbar war````
018-09-02 16:21:01.208 - error: cloud.0 Ping timeoutDer syslog des Raspbis sieht so aus:
Sep 2 15:17:02 ioBroker-RasPi CRON[29768]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Sep 2 16:13:54 ioBroker-RasPi kernel: [415455.785145] INFO: task kworker/1:2:8978 blocked for more than 120 seconds.
Sep 2 16:14:09 ioBroker-RasPi kernel: [415455.785157] Not tainted 4.9.35-v7+ #1014
Sep 2 16:14:17 ioBroker-RasPi kernel: [415455.785161] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep 2 16:14:27 ioBroker-RasPi kernel: [415455.785167] kworker/1:2 D 0 8978 2 0x00000000
Sep 2 16:14:35 ioBroker-RasPi kernel: [415455.785194] Workqueue: events_freezable mmc_rescan
Sep 2 16:14:46 ioBroker-RasPi kernel: [415455.785228] [<807146b0>] (__schedule) from [<80714bd4>] (schedule+0x50/0xa8)
Sep 2 16:14:58 ioBroker-RasPi kernel: [415455.785244] [<80714bd4>] (schedule) from [<805b6c5c>] (__mmc_claim_host+0xb8/0x1cc)
Sep 2 16:15:09 ioBroker-RasPi kernel: [415455.785259] [<805b6c5c>] (__mmc_claim_host) from [<805b6da0>] (mmc_get_card+0x30/0x34)
Sep 2 16:15:17 ioBroker-RasPi kernel: [415455.785274] [<805b6da0>] (mmc_get_card) from [<805bf830>] (mmc_sd_detect+0x2c/0x80)
Sep 2 16:15:25 ioBroker-RasPi kernel: [415455.785290] [<805bf830>] (mmc_sd_detect) from [<805b9a64>] (mmc_rescan+0x1c8/0x38c)
Sep 2 16:15:31 ioBroker-RasPi kernel: [415455.785308] [<805b9a64>] (mmc_rescan) from [<80136660>] (process_one_work+0x158/0x454)
Sep 2 16:15:36 ioBroker-RasPi kernel: [415455.785327] [<80136660>] (process_one_work) from [<801369c0>] (worker_thread+0x64/0x568)
Sep 2 16:15:48 ioBroker-RasPi kernel: [415455.785342] [<801369c0>] (worker_thread) from [<8013c8c8>] (kthread+0x10c/0x124)
Sep 2 16:15:57 ioBroker-RasPi kernel: [415455.785360] [<8013c8c8>] (kthread) from [<80108148>] (ret_from_fork+0x14/0x2c)
Sep 2 16:16:09 ioBroker-RasPi kernel: [415578.665281] INFO: task kworker/1:2:8978 blocked for more than 120 seconds.
Sep 2 16:16:21 ioBroker-RasPi kernel: [415578.665293] Not tainted 4.9.35-v7+ #1014
Sep 2 16:16:28 ioBroker-RasPi kernel: [415578.665297] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep 2 16:16:35 ioBroker-RasPi kernel: [415578.665302] kworker/1:2 D 0 8978 2 0x00000000
Sep 2 16:16:41 ioBroker-RasPi kernel: [415578.665331] Workqueue: events_freezable mmc_rescan
Sep 2 16:16:51 ioBroker-RasPi kernel: [415578.665364] [<807146b0>] (__schedule) from [<80714bd4>] (schedule+0x50/0xa8)
Sep 2 15:17:04 ioBroker-RasPi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="360" x-info="http://www.rsyslog.com"] start
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] Booting Linux on physical CPU 0x0
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] Linux version 4.9.35-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1014 SMP Fri Jun 30 14:47:43 BST 2017
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] CPU: div instructions available: patching division code
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] OF: fdt:Machine model: Raspberry Pi 3 Model B Rev 1.2
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] cma: Reserved 8 MiB at 0x3a800000
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] Memory policy: Data cache writealloc
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] On node 0 totalpages: 241664
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] free_area_init_node: node 0, pgdat 80c6ee40, node_mem_map b9faa000
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] Normal zone: 2124 pages used for memmap
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] Normal zone: 0 pages reserved
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] Normal zone: 241664 pages, LIFO batch:31
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] percpu: Embedded 14 pages/cpu @b9f64000 s25600 r8192 d23552 u57344
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] pcpu-alloc: s25600 r8192 d23552 u57344 alloc=14*4096
Sep 2 15:17:04 ioBroker-RasPi kernel: [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3Da sich der Raspi die Zeit erst während des Boots holt, sieht man auch hier einen Zeitsprung. Der Raspi ist vermutlich bei __16:16:51__ abgestürzt. Diese Zeile kommt mir verdächtig vor:```` INFO: task kworker/1:2:8978 blocked for more than 120 seconds.
top sieht jetzt nach dem Boot so aus:````
top - 17:14:20 up 51 min, 1 user, load average: 0,32, 0,16, 0,19
Tasks: 153 total, 1 running, 152 sleeping, 0 stopped, 0 zombie
%Cpu(s): 8,1 us, 2,0 sy, 0,0 ni, 89,9 id, 0,0 wa, 0,0 hi, 0,0 si, 0,0 st
KiB Mem: 945512 total, 869672 used, 75840 free, 37340 buffers
KiB Swap: 102396 total, 600 used, 101796 free. 119016 cached MemHat jemand eine Idee?
-
Könnte was mit der SD-Karte oder den Treibern/OS sein.
Macht der folgende Befehl eventuell auch nach einigen Minuten Probleme? Mehrmalige Ausführung?
sudo dd if=/dev/mmcblk0 bs=4M status=progress >/dev/null
-
sudo dd if=/dev/mmcblk0 bs=4M status=progress >/dev/null ```` `
Was macht der Befehl denn genau? Ist das nicht ein Bitkopie des kompletten Systems? Aber wohin?!
status=progress ````geht glaub ich nur auf Ubuntu. Das ioBroker ist doch Jessie, oder?
-
Wieso soll es nicht funktionieren? Der Befehl liest die SD und schreibt den gelesenen Inhalt dann ins Nirwana. Mehr nicht.
-
Und dann kucken wir mal, ob das OS nach ein paar Anläufen dabei abstürzt.
-
Ich habe das````
status=progressioBroker läuft noch, im Terminal seh ich halt jetzt keinen Fortschritt o.ä.
-
Hab den Befehl nun zweimal hintereinander ausgeführt. ioBroker läuft noch völlig normal… :roll:
-
Hmm, wenn man wüsste, was der Prozess 8978 aus Deinem Fehlerlog oben war… Siehst Du da mehr im Log?
-
Ist das ein fertiges ioBroker-Image gewesen?
-
Ist das ein fertiges ioBroker-Image gewesen? `
Erstmal vielen, herzlichen Dank für Deine Hilfe.Ja - ich das Rasbian-Image verwendet.
Hmm, wenn man wüsste, was der Prozess 8978 aus Deinem Fehlerlog oben war… Siehst Du da mehr im Log? `
Leider nein. Im Log steht sonst nichts zu diesem "8978". Bis auf die von mir beschriebenen Einträge is das Log recht unspektakulär. Zumindest bis zum (Wieder-)Start des Rapsis. Dann sind die (scheinbar) normalen Hochlaufprozeduren beschrieben.