IoBroker wird beendet

nieIP

Hallo

ich hatte jetzt zum zweiten Mal innerhalb von zwei Wochen einen Ausfall von ioBroker. Heute habe ich nicht einfach nur den RasPi neu gestartet, sondern auch einige Infos gesammelt.

die Web Oberfläche ist nicht erreichbar.
per Terminal komme ich auf den RasPi

root@raspi-3:~# iobroker restart
iobroker controller daemon is not running
Starting iobroker controller daemon...
iobroker controller daemon started. PID: 6848
root@raspi-3:~#

danach funktioniert das System wieder.

Offenbar gab es in der Nacht einen Fehler. Hier das Log File dazu:

2018-12-27 00:18:03.118 - info: host.raspi-3 instance system.adapter.yr.0 started with pid 4554
2018-12-27 00:18:05.042 - info: yr.0 starting. Version 2.0.3 in /opt/iobroker/node_modules/iobroker.yr, node: v6.15.1
2018-12-27 00:18:05.464 - info: yr.0 got weather data from yr.no
2018-12-27 00:18:10.583 - info: host.raspi-3 instance system.adapter.yr.0 terminated with code 0 (OK)
2018-12-27 01:18:03.099 - info: host.raspi-3 instance system.adapter.yr.0 started with pid 4769
2018-12-27 01:18:05.043 - info: yr.0 starting. Version 2.0.3 in /opt/iobroker/node_modules/iobroker.yr, node: v6.15.1
2018-12-27 01:18:05.477 - info: yr.0 got weather data from yr.no
2018-12-27 01:18:10.644 - info: host.raspi-3 instance system.adapter.yr.0 terminated with code 0 (OK)
2018-12-27 01:40:15.723 - info: host.raspi-3 Delete log file iobroker.2018-12-20.log
2018-12-27 02:11:40.101 - warn: host.raspi-3 instance system.adapter.admin.0 terminated due to SIGKILL
2018-12-27 02:11:40.142 - error: host.raspi-3 instance system.adapter.admin.0 terminated with code null ()
2018-12-27 02:11:40.144 - info: host.raspi-3 Restart adapter system.adapter.admin.0 because enabled
2018-12-27 02:12:43.433 - error: uncaught exception: spawn ENOMEM
2018-12-27 02:12:43.354 - error: sql.0 uncaught exception: Quit inactivity timeout
2018-12-27 02:12:43.370 - error: sql.0 Error: Quit inactivity timeout
at Quit. (/opt/iobroker/node_modules/iobroker.sql/node_modules/mysql/lib/protocol/Protocol.js:164:17)
at emitNone (events.js:86:13)
at Quit.emit (events.js:185:7)
at Quit._onTimeout (/opt/iobroker/node_modules/iobroker.sql/node_modules/mysql/lib/protocol/sequences/Sequence.js:129:8)
at ontimeout (timers.js:386:11)
at tryOnTimeout (timers.js:250:5)
at Timer.listOnTimeout (timers.js:214:5)
2018-12-27 02:12:43.411 - warn: sql.0 Exception: Error: Quit inactivity timeout
2018-12-27 02:12:45.013 - error: sql.0 Cannot queue new requests, because more than 100
2018-12-27 10:59:58.997 - info: host.raspi-3 iobroker.js-controller version 1.5.0 js-controller starting
2018-12-27 10:59:59.013 - info: host.raspi-3 Copyright (c) 2014-2018 bluefox, 2014 hobbyquaker
2018-12-27 10:59:59.018 - info: host.raspi-3 hostname: raspi-3, node: v6.15.1
2018-12-27 10:59:59.020 - info: host.raspi-3 ip addresses: 192.168.1.161 fd00::45ec:135f:5ca9:606b fe80::5808:2398:e0a1:1c9d
2018-12-27 10:59:59.328 - info: host.raspi-3 inMem-states listening on port 9000
2018-12-27 11:00:00.757 - info: host.raspi-3 inMem-objects listening on port 9001
2018-12-27 11:00:00.785 - info: host.raspi-3 InMemoryDB connected
2018-12-27 11:00:00.868 - info: host.raspi-3 28 instances found
2018-12-27 11:00:01.078 - info: host.raspi-3 starting 18 instances
2018-12-27 11:00:01.240 - info: host.raspi-3 instance system.adapter.admin.0 started with pid 6860
2018-12-27 11:00:03.761 - warn: hm-rega.0 Reconnection to DB.
2018-12-27 11:00:03.898 - warn: hm-rega.0 Reconnection to DB.
2018-12-27 11:00:04.050 - info: hm-rega.0 starting. Version 2.0.0 in /opt/iobroker/node_modules/iobroker.hm-rega, node: v6.15.1
2018-12-27 11:00:04.076 - info: hm-rega.0 starting. Version 2.0.0 in /opt/iobroker/node_modules/iobroker.hm-rega, node: v6.15.1
2018-12-27 11:00:04.413 - info: hm-rega.0 ReGaHSS 192.168.1.55 up
2018-12-27 11:00:04.420 - info: hm-rega.0 time difference local-ccu NaNs
2018-12-27 11:00:04.431 - info: hm-rega.0 ReGaHSS 192.168.1.55 up
2018-12-27 11:00:04.486 - info: hm-rega.0 time difference local-ccu 0s
2018-12-27 11:00:04.560 - info: hm-rega.0 added/updated 16 favorites to enum.favorites
2018-12-27 11:00:04.665 - info: hm-rega.0 added/updated functions to enum.functions
2018-12-27 11:00:04.794 - info: hm-rega.0 added/updated rooms to enum.rooms
2018-12-27 11:00:05.027 - info: hm-rega.0 got 119 programs
2018-12-27 11:00:05.086 - info: hm-rega.0 added/updated 119 programs
2018-12-27 11:00:05.087 - info: hm-rega.0 deleted 0 programs
2018-12-27 11:00:05.154 - info: host.raspi-3 instance system.adapter.hm-rega.0 started with pid 6866
2018-12-27 11:00:05.391 - info: hm-rega.0 got 139 variables
2018-12-27 11:00:05.534 - info: hm-rega.0 added/updated 139 variables
2018-12-27 11:00:05.535 - info: hm-rega.0 deleted 0 variables
2018-12-27 11:00:07.335 - info: admin.0 starting. Version 3.5.10 in /opt/iobroker/node_modules/iobroker.admin, node: v6.15.1
2018-12-27 11:00:07.457 - info: admin.0 requesting all states
2018-12-27 11:00:07.467 - info: admin.0 requesting all objects
2018-12-27 11:00:07.475 - info: admin.0 Request actual repository...
2018-12-27 11:00:09.138 - info: hm-rega.0 renamed hm-rpc.0._NEQ0245512.1 to "RM_Gruppe_EG_EFH-1"
2018-12-27 11:00:09.210 - info: hm-rega.0 added/updated 3 objects
2018-12-27 11:00:09.211 - info: hm-rega.0 request state values
2018-12-27 11:00:09.756 - info: host.raspi-3 instance system.adapter.web.0 started with pid 6881
2018-12-27 11:00:10.008 - info: hm-rega.0 got state values
2018-12-27 11:00:10.099 - info: hm-rega.0 renamed hm-rpc.0._NEQ0245512.0 to "RM_Gruppe_EG_EFH:0"
2018-12-27 11:00:10.917 - error: host.raspi-3 instance system.adapter.hm-rega.0 terminated with code 7 (Adapter already running)
2018-12-27 11:00:10.919 - info: host.raspi-3 Restart adapter system.adapter.hm-rega.0 because enabled
2018-12-27 11:00:11.481 - info: hm-rega.0 renamed hm-rpc.0._NEQ0245512 to "RM_Gruppe_EG_EFH"
2018-12-27 11:00:13.021 - info: hm-rega.0 renamed hm-rpc.0._NEQ0007213.1 to "RM_Gruppe_DG_EFH-1"

Nach dem Start hatte hm-rega.0 ein Problem, das ist jetzt aber erst mal zweitrangig.

Die Fehlermeldungen ab 02:11 sagen mir leider nichts :(

Jemand eine Idee ?

Stabilostick

Du hast

einen Admin, der beendet wird
kein freies RAM
einen SQL-Adapter, der nicht mehr funktionieren mag.

->Ergibt einen Neustart des js-Controllers.

1. Wieviel Speicher ist normalerweise auf Deinem RPi frei? 18 Adapter eingeschaltet?

2. Welche DB nutzt Du? MySQL? Lokal?

apollon77

Schau mal ob in /var/log/syslog irgendwas zu dem Zeitpunkt steht. Vllt was mit „oom“ ?

Ich tippe du findest was.

Vermutung ram Ist ausgegangen und Linux hat den Admin gekillt. Und hatte dann immer noch speicherprobleme.

Und tippe sql Problem ist auch nur folge davon

Gesendet vom Handy …

Stabilostick

Lektüre zum oom-Killer:

http://bl0rg.krunch.be/oom-frag.html

nieIP

Hallo

ich versuche mal die Fragen zu beantworten

laut Admin Ansicht sind 590Mb Ram frei, schwankt bis 500MB

1282_screenshot_2018-12-27_11.53.24.png

woher die 18 Adapter kommen weiss ich nicht. Ich habe 8 Instanzen die laufen und einen grünen Punkt haben. Einige der eingerichteten Instanzen kann man ja nicht ausschalten. Egal wie ich zähle, sind es entweder weniger oder mehr als 18 :(

1282_screenshot_2018-12-27_11.59.36.png

Ich nutze eine MySQL Datenbank auf einem NAS im lokalen Netz.

Die Software des RasPi wird regelmäßig aktualisiert und die Adapter sind immer auf dem letzten Stand.

Die größten Veränderungen aus meiner Sicht waren in letzter Zeit die Updates vom npm und nodes-js auf die aktuelle Version.

Ja, im Syslog steht etwas. Das einzige was isch daran verstehe ist SWAP=0 und das ioBroker.js ganz viel Speicher belegt.

Also müllt etwas meinen Speicher voll. Wie bekomme ich raus, was da schuld ist?

Dec 27 01:51:37 raspi-3 dhcpcd[445]: eth0: fe80::464e:6dff:fe5f:c568 router available
Dec 27 01:59:18 raspi-3 dhcpcd[445]: eth0: fe80::464e:6dff:fe5f:c568 router available
Dec 27 01:59:18 raspi-3 rsyslogd-2007: action 'action 17' suspended, next retry is Thu Dec 27 01:59:48 2018 [try http://www.rsyslog.com/e/2007 ]
Dec 27 02:07:57 raspi-3 dhcpcd[445]: eth0: fe80::464e:6dff:fe5f:c568 router available
Dec 27 02:07:57 raspi-3 rsyslogd-2007: action 'action 17' suspended, next retry is Thu Dec 27 02:08:27 2018 [try http://www.rsyslog.com/e/2007 ]
Dec 27 02:11:24 raspi-3 kernel: [581478.070053] node invoked oom-killer: gfp_mask=0x14080c0(GFP_KERNEL|__GFP_ZERO), nodemask=(null),  order=0, oom_score_adj=0
Dec 27 02:11:24 raspi-3 kernel: [581478.070066] node cpuset=/ mems_allowed=0
Dec 27 02:11:24 raspi-3 kernel: [581478.070080] CPU: 3 PID: 4944 Comm: node Tainted: G         C      4.14.22-v7+ #1096
Dec 27 02:11:24 raspi-3 kernel: [581478.070083] Hardware name: BCM2835
Dec 27 02:11:24 raspi-3 kernel: [581478.070105] [<8010fff8>] (unwind_backtrace) from [<8010c260>] (show_stack+0x20/0x24)
Dec 27 02:11:24 raspi-3 kernel: [581478.070116] [<8010c260>] (show_stack) from [<80760e4c>] (dump_stack+0xd4/0x118)
Dec 27 02:11:24 raspi-3 kernel: [581478.070127] [<80760e4c>] (dump_stack) from [<802234f0>] (dump_header+0xac/0x208)
Dec 27 02:11:24 raspi-3 kernel: [581478.070136] [<802234f0>] (dump_header) from [<80222d28>] (oom_kill_process+0x478/0x584)
Dec 27 02:11:24 raspi-3 kernel: [581478.070144] [<80222d28>] (oom_kill_process) from [<802231b8>] (out_of_memory+0x124/0x334)
Dec 27 02:11:24 raspi-3 kernel: [581478.070153] [<802231b8>] (out_of_memory) from [<80228c7c>] (__alloc_pages_nodemask+0x1068/0x11e0)
Dec 27 02:11:24 raspi-3 kernel: [581478.070162] [<80228c7c>] (__alloc_pages_nodemask) from [<802550e0>] (__pte_alloc+0x34/0x19c)
Dec 27 02:11:24 raspi-3 kernel: [581478.070171] [<802550e0>] (__pte_alloc) from [<80258dac>] (handle_mm_fault+0xb98/0xc20)
Dec 27 02:11:24 raspi-3 kernel: [581478.070181] [<80258dac>] (handle_mm_fault) from [<8077d54c>] (do_page_fault+0x330/0x3a4)
Dec 27 02:11:24 raspi-3 kernel: [581478.070190] [<8077d54c>] (do_page_fault) from [<8077d67c>] (do_translation_fault+0xbc/0xc0)
Dec 27 02:11:24 raspi-3 kernel: [581478.070199] [<8077d67c>] (do_translation_fault) from [<801011e4>] (do_DataAbort+0x48/0xc4)
Dec 27 02:11:24 raspi-3 kernel: [581478.070207] [<801011e4>] (do_DataAbort) from [<8077cd64>] (__dabt_usr+0x44/0x60)
Dec 27 02:11:24 raspi-3 kernel: [581478.070211] Exception stack(0xa14fdfb0 to 0xa14fdff8)
Dec 27 02:11:24 raspi-3 kernel: [581478.070216] dfa0:                                     01520c68 69700000 00100000 69608100
Dec 27 02:11:24 raspi-3 kernel: [581478.070222] dfc0: 69600000 00000000 00000002 69600000 7ec4ca10 00000000 69600000 7ec4c9e4
Dec 27 02:11:24 raspi-3 kernel: [581478.070227] dfe0: 0153cd13 7ec4c9c8 007dd564 007d6c80 60000010 ffffffff
Dec 27 02:11:24 raspi-3 kernel: [581478.070230] Mem-Info:
Dec 27 02:11:24 raspi-3 kernel: [581478.070242] active_anon:111435 inactive_anon:111481 isolated_anon:0
Dec 27 02:11:24 raspi-3 kernel: [581478.070242]  active_file:52 inactive_file:121 isolated_file:0
Dec 27 02:11:24 raspi-3 kernel: [581478.070242]  unevictable:0 dirty:0 writeback:0 unstable:0
Dec 27 02:11:24 raspi-3 kernel: [581478.070242]  slab_reclaimable:1925 slab_unreclaimable:3035
Dec 27 02:11:24 raspi-3 kernel: [581478.070242]  mapped:525 shmem:517 pagetables:1302 bounce:0
Dec 27 02:11:24 raspi-3 kernel: [581478.070242]  free:5153 free_pcp:193 free_cma:1343
Dec 27 02:11:24 raspi-3 kernel: [581478.070251] Node 0 active_anon:445740kB inactive_anon:445924kB active_file:208kB inactive_file:484kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:2100kB dirty:0kB writeback:0kB shmem:2068kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
Dec 27 02:11:24 raspi-3 kernel: [581478.070263] Normal free:20612kB min:16384kB low:20480kB high:24576kB active_anon:445740kB inactive_anon:445924kB active_file:308kB inactive_file:380kB unevictable:0kB writepending:0kB present:970752kB managed:949476kB mlocked:0kB kernel_stack:1568kB pagetables:5208kB bounce:0kB free_pcp:772kB local_pcp:120kB free_cma:5372kB
Dec 27 02:11:24 raspi-3 kernel: [581478.070265] lowmem_reserve[]: 0 0
Dec 27 02:11:24 raspi-3 kernel: [581478.070273] Normal: 399*4kB (MEC) 239*8kB (UMEC) 165*16kB (UMEC) 81*32kB (UMEC) 64*64kB (UMEC) 18*128kB (UEC) 6*256kB (UEC) 0*512kB 0*1024kB 0*2048kB 1*4096kB (C) = 20772kB
Dec 27 02:11:24 raspi-3 kernel: [581478.070323] 2083 total pagecache pages
Dec 27 02:11:24 raspi-3 kernel: [581478.070327] 1335 pages in swap cache
Dec 27 02:11:24 raspi-3 kernel: [581478.070331] Swap cache stats: add 68325, delete 66990, find 114515/127466
Dec 27 02:11:24 raspi-3 kernel: [581478.070333] Free swap  = 0kB
Dec 27 02:11:24 raspi-3 kernel: [581478.070336] Total swap = 102396kB
Dec 27 02:11:24 raspi-3 kernel: [581478.070338] 242688 pages RAM
Dec 27 02:11:24 raspi-3 kernel: [581478.070340] 0 pages HighMem/MovableOnly
Dec 27 02:11:24 raspi-3 kernel: [581478.070343] 5319 pages reserved
Dec 27 02:11:24 raspi-3 kernel: [581478.070348] 2048 pages cma reserved
Dec 27 02:11:24 raspi-3 kernel: [581478.070353] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
Dec 27 02:11:24 raspi-3 kernel: [581478.070375] [   98]     0    98     2488      502       9       0       65             0 systemd-journal
Dec 27 02:11:24 raspi-3 kernel: [581478.070382] [  113]     0   113     3008       16       7       0      190         -1000 systemd-udevd
Dec 27 02:11:24 raspi-3 kernel: [581478.070389] [  428]   105   428     1067       61       8       0       82             0 avahi-daemon
Dec 27 02:11:24 raspi-3 kernel: [581478.070395] [  433]     0   433     1327        7       6       0       43             0 cron
Dec 27 02:11:24 raspi-3 kernel: [581478.070401] [  439]     0   439     8035        0      11       0      201             0 rsyslogd
Dec 27 02:11:24 raspi-3 kernel: [581478.070406] [  444]   104   444     1372        5       6       0       87          -900 dbus-daemon
Dec 27 02:11:24 raspi-3 kernel: [581478.070412] [  445]     0   445      640       13       5       0       58             0 dhcpcd
Dec 27 02:11:24 raspi-3 kernel: [581478.070418] [  469] 65534   469      572        4       5       0       27             0 thd
Dec 27 02:11:24 raspi-3 kernel: [581478.070424] [  479]   105   479      968        0       5       0       57             0 avahi-daemon
Dec 27 02:11:24 raspi-3 kernel: [581478.070430] [  536]     0   536      848       10       7       0       42             0 systemd-logind
Dec 27 02:11:24 raspi-3 kernel: [581478.070436] [  538]     0   538     1788       14       7       0       91             0 wpa_supplicant
Dec 27 02:11:24 raspi-3 kernel: [581478.070442] [  628]   106   628     1421       31       7       0       80             0 ntpd
Dec 27 02:11:24 raspi-3 kernel: [581478.070453] [  633]     0   633     1072        1       7       0       32             0 agetty
Dec 27 02:11:24 raspi-3 kernel: [581478.070461] [  674]     0   674     1964        1       7       0      114         -1000 sshd
Dec 27 02:11:24 raspi-3 kernel: [581478.070469] [  767]     0   767   135838   105902     376       0     3617             0 iobroker.js-con
Dec 27 02:11:24 raspi-3 kernel: [581478.070475] [  784]     0   784      516        0       6       0       33             0 hciattach
Dec 27 02:11:24 raspi-3 kernel: [581478.070481] [  789]     0   789     1251        0       7       0       67             0 bluetoothd
Dec 27 02:11:24 raspi-3 kernel: [581478.070487] [  791]     0   791     5691       63      14       0      238             0 nmbd
Dec 27 02:11:24 raspi-3 kernel: [581478.070493] [  804]     0   804     8986       48      21       0      372             0 smbd
Dec 27 02:11:24 raspi-3 kernel: [581478.070500] [  807]     0   807     8986       47      19       0      373             0 smbd
Dec 27 02:11:24 raspi-3 kernel: [581478.070506] [ 1032]     0  1032    32918     4380      57       0      972             0 io.email.0
Dec 27 02:11:24 raspi-3 kernel: [581478.070513] [26536]     0 26536    41698     3667      74       0     8338             0 io.admin.0
Dec 27 02:11:24 raspi-3 kernel: [581478.070519] [26542]     0 26542    36635     3117      61       0     4185             0 io.hm-rega.0
Dec 27 02:11:24 raspi-3 kernel: [581478.070525] [26548]     0 26548    38769     4965      64       0     3860             0 io.web.0
Dec 27 02:11:24 raspi-3 kernel: [581478.070531] [29095]     0 29095    32331     5183      56       0        0             0 io.backitup.0
Dec 27 02:11:24 raspi-3 kernel: [581478.070536] [29180]     0 29180    35354     6049      62       0        9             0 io.hm-rpc.0
Dec 27 02:11:24 raspi-3 kernel: [581478.070542] [29186]     0 29186    33956     4767      55       0       33             0 io.hm-rpc.1
Dec 27 02:11:24 raspi-3 kernel: [581478.070548] [ 3420]     0  3420    36608     6956      64       0        0             0 io.sql.0
Dec 27 02:11:24 raspi-3 kernel: [581478.070556] [ 4944]     0  4944    92070    74743     259       0        0             0 node
Dec 27 02:11:24 raspi-3 kernel: [581478.070561] Out of memory: Kill process 767 (iobroker.js-con) score 405 or sacrifice child
Dec 27 02:11:24 raspi-3 kernel: [581478.070611] Killed process 26536 (io.admin.0) total-vm:166792kB, anon-rss:14668kB, file-rss:0kB, shmem-rss:0kB
Dec 27 02:11:24 raspi-3 kernel: [581478.099975] oom_reaper: reaped process 26536 (io.admin.0), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Dec 27 02:11:25 raspi-3 rsyslogd-2007: action 'action 17' suspended, next retry is Thu Dec 27 02:11:55 2018 [try http://www.rsyslog.com/e/2007 ]
Dec 27 02:12:42 raspi-3 kernel: [581558.184574] io.hm-rpc.1 invoked oom-killer: gfp_mask=0x14142c0(GFP_KERNEL|__GFP_NOWARN|__GFP_COMP|__GFP_NOMEMALLOC), nodemask=(null),  order=0, oom_score_adj=0
Dec 27 02:12:42 raspi-3 kernel: [581558.184589] io.hm-rpc.1 cpuset=/ mems_allowed=0
Dec 27 02:12:42 raspi-3 kernel: [581558.184605] CPU: 1 PID: 29186 Comm: io.hm-rpc.1 Tainted: G         C      4.14.22-v7+ #1096
Dec 27 02:12:42 raspi-3 kernel: [581558.184608] Hardware name: BCM2835
Dec 27 02:12:42 raspi-3 kernel: [581558.184629] [<8010fff8>] (unwind_backtrace) from [<8010c260>] (show_stack+0x20/0x24)
Dec 27 02:12:42 raspi-3 kernel: [581558.184639] [<8010c260>] (show_stack) from [<80760e4c>] (dump_stack+0xd4/0x118)
Dec 27 02:12:42 raspi-3 kernel: [581558.184652] [<80760e4c>] (dump_stack) from [<802234f0>] (dump_header+0xac/0x208)
Dec 27 02:12:42 raspi-3 kernel: [581558.184661] [<802234f0>] (dump_header) from [<80222d28>] (oom_kill_process+0x478/0x584)
Dec 27 02:12:42 raspi-3 kernel: [581558.184669] [<80222d28>] (oom_kill_process) from [<802231b8>] (out_of_memory+0x124/0x334)
Dec 27 02:12:42 raspi-3 kernel: [581558.184678] [<802231b8>] (out_of_memory) from [<80228c7c>] (__alloc_pages_nodemask+0x1068/0x11e0)
Dec 27 02:12:42 raspi-3 kernel: [581558.184687] [<80228c7c>] (__alloc_pages_nodemask) from [<802740f8>] (new_slab+0x454/0x558)
Dec 27 02:12:42 raspi-3 kernel: [581558.184695] [<802740f8>] (new_slab) from [<80275f3c>] (___slab_alloc.constprop.11+0x228/0x2c0)
Dec 27 02:12:42 raspi-3 kernel: [581558.184703] [<80275f3c>] (___slab_alloc.constprop.11) from [<80276018>] (__slab_alloc.constprop.10+0x44/0x90)
Dec 27 02:12:42 raspi-3 kernel: [581558.184711] [<80276018>] (__slab_alloc.constprop.10) from [<80279318>] (__kmalloc_track_caller+0x244/0x278)
Dec 27 02:12:42 raspi-3 kernel: [581558.184722] [<80279318>] (__kmalloc_track_caller) from [<8065239c>] (__kmalloc_reserve+0x34/0x80)
Dec 27 02:12:42 raspi-3 kernel: [581558.184732] [<8065239c>] (__kmalloc_reserve) from [<80652464>] (__alloc_skb+0x7c/0x144)
Dec 27 02:12:42 raspi-3 kernel: [581558.184741] [<80652464>] (__alloc_skb) from [<806c3edc>] (sk_stream_alloc_skb+0x5c/0x1d0)
Dec 27 02:12:42 raspi-3 kernel: [581558.184751] [<806c3edc>] (sk_stream_alloc_skb) from [<806c4ba8>] (tcp_sendmsg_locked+0x470/0xdfc)
Dec 27 02:12:42 raspi-3 kernel: [581558.184759] [<806c4ba8>] (tcp_sendmsg_locked) from [<806c556c>] (tcp_sendmsg+0x38/0x4c)
Dec 27 02:12:42 raspi-3 kernel: [581558.184768] [<806c556c>] (tcp_sendmsg) from [<806f14f8>] (inet_sendmsg+0x48/0xe4)
Dec 27 02:12:42 raspi-3 kernel: [581558.184779] [<806f14f8>] (inet_sendmsg) from [<8064adb8>] (sock_sendmsg+0x24/0x34)
Dec 27 02:12:42 raspi-3 kernel: [581558.184786] [<8064adb8>] (sock_sendmsg) from [<8064ae60>] (sock_write_iter+0x98/0xcc)
Dec 27 02:12:42 raspi-3 kernel: [581558.184795] [<8064ae60>] (sock_write_iter) from [<8028a184>] (__vfs_write+0xe0/0x138)
Dec 27 02:12:42 raspi-3 kernel: [581558.184804] [<8028a184>] (__vfs_write) from [<8028a3a4>] (vfs_write+0xb4/0x1bc)
Dec 27 02:12:42 raspi-3 kernel: [581558.184812] [<8028a3a4>] (vfs_write) from [<8028a5f4>] (SyS_write+0x54/0xb0)
Dec 27 02:12:42 raspi-3 kernel: [581558.184821] [<8028a5f4>] (SyS_write) from [<80108080>] (ret_fast_syscall+0x0/0x28)
Dec 27 02:12:42 raspi-3 kernel: [581558.184824] Mem-Info:
Dec 27 02:12:42 raspi-3 kernel: [581558.184837] active_anon:111515 inactive_anon:111537 isolated_anon:0
Dec 27 02:12:42 raspi-3 kernel: [581558.184837]  active_file:126 inactive_file:325 isolated_file:0
Dec 27 02:12:42 raspi-3 kernel: [581558.184837]  unevictable:0 dirty:0 writeback:1 unstable:0
Dec 27 02:12:42 raspi-3 kernel: [581558.184837]  slab_reclaimable:1898 slab_unreclaimable:2971
Dec 27 02:12:42 raspi-3 kernel: [581558.184837]  mapped:484 shmem:526 pagetables:1317 bounce:0
Dec 27 02:12:42 raspi-3 kernel: [581558.184837]  free:5044 free_pcp:0 free_cma:1024
Dec 27 02:12:42 raspi-3 kernel: [581558.184846] Node 0 active_anon:446060kB inactive_anon:446148kB active_file:504kB inactive_file:1300kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:1936kB dirty:0kB writeback:4kB shmem:2104kB writeback_tmp:0kB unstable:0kB all_unreclaimable? yes
Dec 27 02:12:42 raspi-3 kernel: [581558.184858] Normal free:20176kB min:16384kB low:20480kB high:24576kB active_anon:446060kB inactive_anon:446148kB active_file:504kB inactive_file:1328kB unevictable:0kB writepending:4kB present:970752kB managed:949476kB mlocked:0kB kernel_stack:1536kB pagetables:5268kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:4096kB
Dec 27 02:12:42 raspi-3 kernel: [581558.184860] lowmem_reserve[]: 0 0
Dec 27 02:12:42 raspi-3 kernel: [581558.184867] Normal: 550*4kB (MEC) 281*8kB (MEC) 165*16kB (UMEC) 79*32kB (UMEC) 59*64kB (UMEC) 19*128kB (UEC) 5*256kB (UE) 0*512kB 1*1024kB (C) 1*2048kB (C) 0*4096kB = 20176kB
Dec 27 02:12:42 raspi-3 kernel: [581558.184913] 1273 total pagecache pages
Dec 27 02:12:42 raspi-3 kernel: [581558.184917] 280 pages in swap cache
Dec 27 02:12:42 raspi-3 kernel: [581558.184921] Swap cache stats: add 78870, delete 78590, find 115667/129829
Dec 27 02:12:42 raspi-3 kernel: [581558.184923] Free swap  = 0kB
Dec 27 02:12:42 raspi-3 kernel: [581558.184926] Total swap = 102396kB
Dec 27 02:12:42 raspi-3 kernel: [581558.184928] 242688 pages RAM
Dec 27 02:12:42 raspi-3 kernel: [581558.184931] 0 pages HighMem/MovableOnly
Dec 27 02:12:42 raspi-3 kernel: [581558.184933] 5319 pages reserved
Dec 27 02:12:42 raspi-3 kernel: [581558.184935] 2048 pages cma reserved
Dec 27 02:12:42 raspi-3 kernel: [581558.184938] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
Dec 27 02:12:42 raspi-3 kernel: [581558.184958] [   98]     0    98     2488      450       9       0       41             0 systemd-journal
Dec 27 02:12:42 raspi-3 kernel: [581558.184966] [  113]     0   113     3008       16       7       0      190         -1000 systemd-udevd
Dec 27 02:12:42 raspi-3 kernel: [581558.184972] [  428]   105   428     1067       61       8       0       82             0 avahi-daemon
Dec 27 02:12:42 raspi-3 kernel: [581558.184978] [  433]     0   433     1327       11       6       0       39             0 cron
Dec 27 02:12:42 raspi-3 kernel: [581558.184984] [  439]     0   439     8035       58      11       0      139             0 rsyslogd
Dec 27 02:12:42 raspi-3 kernel: [581558.184990] [  444]   104   444     1372        5       6       0       87          -900 dbus-daemon
Dec 27 02:12:42 raspi-3 kernel: [581558.184996] [  445]     0   445      640       13       5       0       58             0 dhcpcd
Dec 27 02:12:42 raspi-3 kernel: [581558.185002] [  469] 65534   469      572        4       5       0       27             0 thd
Dec 27 02:12:42 raspi-3 kernel: [581558.185008] [  479]   105   479      968        0       5       0       57             0 avahi-daemon
Dec 27 02:12:42 raspi-3 kernel: [581558.185014] [  536]     0   536      848       16       7       0       36             0 systemd-logind
Dec 27 02:12:42 raspi-3 kernel: [581558.185020] [  538]     0   538     1788       14       7       0       91             0 wpa_supplicant
Dec 27 02:12:42 raspi-3 kernel: [581558.185026] [  628]   106   628     1421       31       7       0       80             0 ntpd
Dec 27 02:12:42 raspi-3 kernel: [581558.185032] [  633]     0   633     1072        1       7       0       32             0 agetty
Dec 27 02:12:42 raspi-3 kernel: [581558.185045] [  674]     0   674     1964        1       7       0      114         -1000 sshd
Dec 27 02:12:42 raspi-3 kernel: [581558.185052] [  767]     0   767   136510    98074     378       0    12232             0 iobroker.js-con
Dec 27 02:12:42 raspi-3 kernel: [581558.185059] [  784]     0   784      516        0       6       0       33             0 hciattach
Dec 27 02:12:42 raspi-3 kernel: [581558.185065] [  789]     0   789     1251        0       7       0       67             0 bluetoothd
Dec 27 02:12:42 raspi-3 kernel: [581558.185078] [  791]     0   791     5691       64      14       0      237             0 nmbd
Dec 27 02:12:42 raspi-3 kernel: [581558.185089] [  804]     0   804     8986       48      21       0      372             0 smbd
Dec 27 02:12:42 raspi-3 kernel: [581558.185102] [  807]     0   807     8986       47      19       0      373             0 smbd
Dec 27 02:12:42 raspi-3 kernel: [581558.185112] [ 1032]     0  1032    32918     4290      57       0      904             0 io.email.0
Dec 27 02:12:42 raspi-3 kernel: [581558.185119] [26542]     0 26542    36635     3391      61       0     4143             0 io.hm-rega.0
Dec 27 02:12:42 raspi-3 kernel: [581558.185125] [26548]     0 26548    38769     5052      64       0     3813             0 io.web.0
Dec 27 02:12:42 raspi-3 kernel: [581558.185131] [29095]     0 29095    32331     5220      56       0        0             0 io.backitup.0
Dec 27 02:12:42 raspi-3 kernel: [581558.185137] [29180]     0 29180    35866     6226      64       0        4             0 io.hm-rpc.0
Dec 27 02:12:42 raspi-3 kernel: [581558.185142] [29186]     0 29186    33956     4828      55       0       27             0 io.hm-rpc.1
Dec 27 02:12:42 raspi-3 kernel: [581558.185148] [ 3420]     0  3420    36608     6871      64       0        0             0 io.sql.0
Dec 27 02:12:42 raspi-3 kernel: [581558.185159] [ 4944]     0  4944   112167    87036     325       0        1             0 node
Dec 27 02:12:42 raspi-3 kernel: [581558.185166] [ 4962]     0  4962     8986       83      19       0      337             0 smbd
Dec 27 02:12:42 raspi-3 kernel: [581558.185170] Out of memory: Kill process 767 (iobroker.js-con) score 408 or sacrifice child
Dec 27 02:12:42 raspi-3 kernel: [581558.185221] Killed process 26548 (io.web.0) total-vm:155076kB, anon-rss:20208kB, file-rss:0kB, shmem-rss:0kB
Dec 27 02:12:42 raspi-3 kernel: [581558.207821] oom_reaper: reaped process 26548 (io.web.0), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Dec 27 02:12:43 raspi-3 rsyslogd-2007: action 'action 17' suspended, next retry is Thu Dec 27 02:13:12 2018 [try http://www.rsyslog.com/e/2007 ]
Dec 27 02:17:01 raspi-3 rsyslogd-2007: action 'action 17' suspended, next retry is Thu Dec 27 02:17:31 2018 [try http://www.rsyslog.com/e/2007 ]
Dec 27 02:17:01 raspi-3 CRON[4972]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Dec 27 02:17:30 raspi-3 dhcpcd[445]: eth0: fe80::464e:6dff:fe5f:c568 router available
Dec 27 02:27:27 raspi-3 dhcpcd[445]: eth0: fe80::464e:6dff:fe5f:c568 router available
Dec 27 02:27:27 raspi-3 rsyslogd-2007: action 'action 17' suspended, next retry is Thu Dec 27 02:27:57 2018 [try http://www.rsyslog.com/e/2007 ]
Dec 27 02:34:48 raspi-3 avahi-daemon[428]: Invalid response packet from host 192.168.1.158.

apollon77

Die Adapter ohne Punkt sind Web Erweiterungen Dir keinen Prozess haben oder vis Widgets bzw Icon sets die auch keinen Prozess haben.

Am Ende hat er heute Nacht nicht den js-Controller gekillt sondern einzelne seiner Prozesse. Das sagt das log. Kannst ja mal schauen ob der Controller immer 100mb braucht. Kann aber gut sein weil er ja auch alle deine Daten (States und Objekte) im Speicher hält. Wie groß ist denn deine Installation so? ;-)

Am Ende steht im log das er zuerst geswappt hat und als swap voll war hat er den Prozess gekillt den er dich ausgesucht hat (muss nicht unbedingt der Verursacher sein!)

Gesendet vom Handy …

apollon77

Die Frage bleibt was die Ursache war.

Gesendet vom Handy …

Stabilostick

Wenn Du wissen möchtest, was passiert, könnte Dir das Script v3 von hier helfen:

viewtopic.php?f=21&t=2935

nieIP

~~@apollon77:~~

Wie groß ist denn deine Installation so? ;-) `

so ca. 150 Geräte. CCU3

Ich möchte wie jeder User einfach nur, dass es läuft. Ein Jahr lang hat es das auch problemlos getan.

Vor 6 Wochen habe ich wegen eigener Dummheit die Daten der letzen 2 Jahre aus der SQL Datenbank verloren. Ich habe vergessen ein Backup einzurichten :oops:

Jetzt musste ich eine neue Datenbank anfangen, mit Backup auf dem NAS und zusätzlich mit backitup. So weit alles gut, dachte ich und nun läuft ioBroker nicht mehr durch :(

apollon77

Wann macht er das Backup? Ist er immer gegen 2 Uhr gestorben?

Gesendet vom Handy …

nieIP

~~@apollon77:~~

Wann macht er das Backup? Ist er immer gegen 2 Uhr gestorben? `

Standard Backup 02:10 täglich - das könnte einen Zusammenhang geben

Komplett Backup 03:00 alle 8 Tage

CCU 4:30 alle 10 tage

Mysql zusammen mit Komplett Backup

Homoran

Habe mal eben quergelesen,

Ja es ist der Speicher! im ersten log

2018-12-27 02:12:43.433 - error: uncaught exception: spawn ENOMEM

und wenn das Backup um 2:10 beginnt passt auch der Timestamp.

~~@nieIP:~~

so ca. 150 Geräte. CCU3 `
Die Frage nach der Größe der Installation bezog sich auf ioBroker ;-)

Anhand des Screenshots deiner Instanzen kann man es aber abschätzen.

Ich weiß nicht wieviel Speicher der SQL Adapter bei dir belegt, aber ich fürchte du bist mit den 1MB eines RasPi allmählich am Ende.

~~@nieIP:~~

Ich möchte wie jeder User einfach nur, dass es läuft. `
Wollen wir auch!

~~@nieIP:~~

und nun läuft ioBroker nicht mehr durch `
Wenn ich dir jetzt raten würde das Backup mal abzuschalten, um das als Ursache auszuschließen, fühle ich mich nicht so richtig wohl dabei.

Wenn du am System nichts änderst wären in extremo nur die aktuellen States verloren, die History speicherst du ja extern in SQL.

Oder übersehe ich da etwas?

Gruß

Rainer

dondaik

als einwurf, das backup wird es nicht oder nur am rande sein … meine laufen um 2 durch durch. der iobroker hat heute schon mindesten 5x gesagt das er nicht mag.... gerade hat er sich erst wieder beendet.. sudo iobroker start hat ihn wohl wieder auf die beine geholfen ... ...

nieIP

~~@Homoran:~~

Ich weiß nicht wieviel Speicher der SQL Adapter bei dir belegt, aber ich fürchte du bist mit den 1MB eines RasPi allmählich am Ende. `

500MB benutzt / 500MB frei und wie gesagt, es lief auch 1 Jahr ohne Probleme
ich warte auf den nächsten Absturz, das sehe ich sofort morgens an VIS. Dann werde ich wieder nach der Zeit sehen und dann ggf. das Backup abschalten.

Gibt es nicht im System Adapter einen Datenpunkt für den freien Speicher? den könnte ich ja mal loggen. Ob es kontinuierlich weniger wird ….

nieIP

host.raspi-3.freemem

in den letzten 3 Tagen gab es 2 mal einen Sprung um 02:10. Genau zu der Zeit wenn dass Backup (Standard) läuft.

Vor einigen Tagen auch um 03:00 , wenn das Komplett Backup läuft.

(der lange schräge Strich heute früh bedeutet nur - keine Daten)

1282_screenshot_2018-12-27_18.18.27.png

nieIP

PS js-controller 1.5.0 falls das wichtig ist

Stabilostick

Da müsste es auch bei den Adaptern Speichercounter geben, die die Speichernutzung pro Adapter anzeigen.

System.Adapter.

nieIP

~~@Stabilostick:~~

Da müsste es auch bei den Adaptern Speichercounter geben, die die Speichernutzung pro Adapter anzeigen.

System.Adapter. `

ja, gibt es. Welchen von den drei Werten sollte ich beobachten? Die Bezeichnungen sagen mir nix :roll:

1282_screenshot_2018-12-27_19.23.40.png

apollon77

Also ja ich würde auch denke das der Backup Adapter an der Stelle mehr Speicher verbraucht als da ist. Warum auch immer. Das müsste man mal rausfinden. :-(

Zum js-Controller … die 1.5.0 hatte auch einige Probleme und die 1.5.3 wäre denke ich besser. Will aber auch nicht zu viele changes zumuten ...

Gesendet vom Handy ...

nieIP

~~@apollon77:~~

Zum js-Controller … die 1.5.0 hatte auch einige Probleme und die 1.5.3 wäre denke ich besser. Will aber auch nicht zu viele changes zumuten ... `

die 1.5.3 muss ich sicherlich per Kommandozeile installieren. Könnte ich bitte die entsprechende Zeile mit dem Befehl mal bekommen?

Community Forum

NEWS

IoBroker wird beendet

Support us

654

32.7k

82.5k

1.3m