Error and Crash - Ineffective mark-compacts near heap limit Allocation

[liv-in-sky]

hi , I got the following error from syslog (is not a raspy - only the name! - 4GB ram- beelink proxmox VM ) - js-cont. 1.5.12 js 4.1.13, node 10.16

Jul 10 12:15:01 raspberry3 CRON[13490]: (root) CMD (/usr/local/bin/mountstatus)
Jul 10 12:15:24 raspberry3 bash[358]: <--- Last few GCs --->
Jul 10 12:15:24 raspberry3 bash[358]: [358:0x3812940] 20777946 ms: Mark-sweep 1396.5 (1419.7) -> 1396.5 (1420.7) MB, 1632.9 / 0.0 ms  (average mu = 0.133, current mu = 0.001) allocation failure scavenge might not succeed
Jul 10 12:15:24 raspberry3 bash[358]: [358:0x3812940] 20779604 ms: Mark-sweep 1397.5 (1420.7) -> 1397.4 (1421.7) MB, 1656.8 / 0.0 ms  (average mu = 0.070, current mu = 0.001) allocation failure scavenge might not succeed
Jul 10 12:15:24 raspberry3 bash[358]: <--- JS stacktrace --->
Jul 10 12:15:24 raspberry3 bash[358]: ==== JS stack trace =========================================

more here: syslog-fehler.txt

iobroker log at the same time: syslog-fehler-iobroker.txt

there are no scripts with errors

any idea what I can do against ? do you need more info? thanx in advance

[AlCalzone]

Jul 10 12:15:24 raspberry3 bash[358]:  3: 0xaffd0e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [iobroker.js-controller]
Jul 10 12:15:24 raspberry3 bash[358]:  4: 0xafff44 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [iobroker.js-controller]

It seems that js-controller ran out of memory. Why? I don't know. You could trace its memory consumption with history and grafana/flot - maybe this helps in finding when and why it happened.

[Apollon77]

This is always interesting what the "around" effects were ... so maybe something/swapping blocked the system? or somehing

more details needed to research. Sowe need to ewait till it happens again to hopefully gain more info

[liv-in-sky]

same error again red line is free memory because of this line: FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory I have disabled a few scripts, which startet a short time before the crash - no error in the iobroker log!

I will go on with watching the next days

I have found this.- https://github.com/Chatie/wechaty/issues/1435 - could it be that javascript needs more memory?

[AlCalzone]

Which process' memory are you plotting? 1.4 GB seems much to high for any of ioBroker's processes. The highest I've personally seen was 300 MB.

[Apollon77]

How many objects and states do you have? Are you using redis?

[Apollon77]

My ioBroker installation uses 142MB controller with peaks to 220MB but uses Redis for Objects (only 13MB Redis mem Res usage, so not much) I have Objects: 13546, States: 11503

And also nodejs 10.16.0

[liv-in-sky]

@AlCalzone - this plot is made by "free -k" . the processes are here:

[liv-in-sky]

@Apollon77 I don't use redis - here are my states number I have to wait until 13:00 or 14:00 - I switch the server on at 6:30 every day -at he moment it is running

[AlCalzone]

That looks pretty normal. Do you have the possibility to record the memory consumption just before it crashes?

[liv-in-sky]

@AlCalzone the first picture is the memory before the crash - there is a small gab at 18:15 - this was the crash OR do you mean you want to see the memory of the single service usage before the crash

[AlCalzone]

do you mean you want to see the memory of the single service usage before the crash

that, yes :)

[AlCalzone]

I had a similar problem once and traced it using iobroker.history and flot. Later it turned out to be a memory leak in NodeJS. But I only found that by plotting the memory consumption for all instances.

[Apollon77]

@liv-in-sky How big your objects.json and states.json in iobroker-data directory are?

[Apollon77]

Then later today please monitor with "top" sorted my Mem usage (press shift-m in top) and look what exactly is happening on mem usage side

[liv-in-sky]

@Apollon77

@AlCalzone @Apollon77 I have created this log every 30 seconds - is this what you mean? if you download the file and rename it with .html instead of .txt - it will become a better view

logprocesses2-11-07-09-38-04-675.txt

[Apollon77]

unübersichtlich aber ja.

EInwas noch: Sch mal ob um die Zeit des letzten crashes was in /var/log/syslog steht, such auch nach OOM oder so

[liv-in-sky]

@Apollon77

zeile 1968 mit notepad++ (12:15:24 Uhr)

syslog.txt

[liv-in-sky]

@Apollon77 hier ein längeres syslog - da kommt oom öfter vor syslog2.txt

[liv-in-sky]

@Apollon77, @AlCalzone
etwas sehr komisches ist geschehen - es ist wieder passiert und zwar um 12:15 - wie gestern - also habe ich gesucht, welches script da laufen könnte entdeckt habe ich ein bashscript in crontab - welches alle 2 stunden mit 15 minuten startet (.. 10:15 12:15, 14:15,16:15;18:15, ...) 12:15 und 18:15 sind 2 absturzzeiten das script: `find "/opt/iobroker/backups/" -name "*.gz" -type f -mtime +1 -delete iobroker backup

rm /mSata/iobroker/.gz rsync -avh /opt/iobroker/backups/ /mSata/iobroker`

also ein iobroker backup aufruf - die beiden files um 12:15 und 18:15 sind nicht im verzeichnis !? wurden nicht erstellt

habt ihr eine idee

[Apollon77]

Also Effekte die ich kenne ist das Linux ja gern RAM nutzt um File Aktionen zu cachen und das hat bei mir auch schonmal für Probleme gesorgt mit OOM Situationen wegen parallelen solchen Aktionen

[liv-in-sky]

@Apollon77 du denkst es liegt mehr an linux bei der "kopiererei" als am iobroker backup aufruf - ich werd mal das kopieren und löschen der files auf einen anderen zeitpunkt legen - ind diesem script werden noch einige andere sachen kopiert und verschoben z.b " rsync -avh /opt/iobroker/iobroker-data/files/vis.0/armin/img/* /mSata/iobroker/image/visarmin

rsync wird sicher resourcen nehmen

[Apollon77]

kann ich nicht sagen, rsync deke auch als eher kandidat

[liv-in-sky]

@Apollon77

backup läuft alle 2 stunden bei 7 minuten files löschen und kopieren alle 2 stunden bei minute 15

mal sehen was rauskommt

[Apollon77]

So oft? Wow ...

[liv-in-sky]

naja - wenn ich mal programmiere oder die vis ändere, sollten die sachen auf jeden fall gespeichert werden - zwei stunden ist da garnichts - in 2 stunden machst du locker eine neue view oder einen langen code - das wäre weg, wenn darin ein festplatten crash wäre

[Apollon77]

Mit Redis (im aktuellen Fall erstmal nur für States) nutze ich das Redis Slaves auf nem zweiten Host ... da wird alles hin gesyct. Falls der Master wegbricht ist alles dort der letzte Stand. AB COntroller 2.0 geht das auch mit Objekten

[liv-in-sky]

ich habe nur von redis gehört - aber mich nie damit beschäftigt - ich werd mal suchen, ob ich die anleitung dazu finde

mit der zeit werde ich auch meine dienste auf andere lxc umleiten z.b. minidlna (10000 files) und mysql - aber die ganzen js- and bashscripte zu ändern ist echt aufwendig - sodas die vm nur noch iobroker hat

[liv-in-sky]

@Apollon77 hallo ingo - ich dachte schon es ist jetzt gut - aber leider stürzt er mit dem fehler beim aufruf des backups ab - ich habe ja die ganzen kopierscripts nach hinten geschoben - der backup job ("backup iobroker") ist der einzige job der zu diesem zeitpunkt lief! - noch ideen was man machen könnte das speicherverhalten zeigte keine änderungen das backup um 20:07 fehlt wieder größe backupfile:

[Apollon77]

Sagt /var/log/syslog was?

[liv-in-sky]

das selbe wie davor - identischer fehler

speicheraufteilung davor und danach:

[liv-in-sky]

wollte mich nochmal melden - habe wieder einen fehler

ich habe etwas verwirrendes festgestellt: ichj habe wohl 2 admin adapter installiert - eine 3er und eine 2 version:

der port 8082 wird nicht benutzt - ich benutze den admin mit 8081 - leider weiß ich nicht mehr, wie der zweite admin da rauf kam - habt ihr einen tipp, wie ich den deinstallieren kann ?

nach dieser fehlermeldung bleibt die cpu auslastung des js-controller ziemlich hoch ca 80% - irgendwann crashed es dann auch

zusatz: natürlich nutze ich den web.0 - meine tablets benutzen ihn als webserver

[AlCalzone]

ich habe etwas verwirrendes festgestellt: ichj habe wohl 2 admin adapter installiert

Nee, das ist die Adapterliste, nicht die Instanzenliste. Neben Admin 3 steht, dass du eine Instanz davon installiert hast.

[Apollon77]

uuui i klingt wie das Issue von Arteck ... --> https://github.com/ioBroker/ioBroker.web/issues/20

[liv-in-sky]

@Apollon77 - ja könnte selbes problem sein @AlCalzone - sorry du hast recht - aber bei einer fehlersuche, bei der man nicht mehr weiß, wo man suchen soll, wird man irgendwann gaga

[liv-in-sky]

hallo,

habe immer noch das problem mit dem crash , meist wenn backup läuft und der server schon eine zeit läuft (halben tag)- kann es sein das die node version da probleme hat? node v10.16.2 - die fehler sind immer andere geworden - nur das wort heap kommt immer drin vor - die fehler wurden anders, da ich alle anderen processe (mysql, nas (samba), webserver (lighttpd, unifi-controller,,..) entfernt habe - zusätzlich ist auch noch redis als datenbank (states) dazugekommen auch der backitup adapter erzeugt einen fehler. sichtbar ist es immer durch hohe cpu werte bei js-controller und 2 javascript instanzen - es ist genügend speicher auf dem server vorhanden letzter fehler:

Aug 18 18:36:50 raspberry3 bash[425]: [425:0x42e8940] 13087811 ms: Mark-sweep 1412.0 (1436.8) -> 141 2.2 (1439.3) MB, 2206.6 / 0.0 ms (average mu = 0.174, current mu = 0.008) allocation failure scaven ge might not succeed Aug 18 18:36:50 raspberry3 bash[425]: [425:0x42e8940] 13089894 ms: Mark-sweep 1415.1 (1439.3) -> 141 5.2 (1439.8) MB, 2077.6 / 0.0 ms (average mu = 0.090, current mu = 0.003) allocation failure scaven ge might not succeed Aug 18 18:36:50 raspberry3 bash[425]: <--- JS stacktrace ---> Aug 18 18:36:50 raspberry3 bash[425]: Cannot get stack trace in GC. Aug 18 18:36:50 raspberry3 bash[425]: FATAL ERROR: MarkCompactCollector: semi-space copy, fallback i n old gen Allocation failed - JavaScript heap out of memory Aug 18 18:36:50 raspberry3 bash[425]: 1: 0x8fa060 node::Abort() [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 2: 0x8fa0ac [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 3: 0xaff7ee v8::Utils::ReportOOMFailure(v8::internal::Isolate *, char const*, bool) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 4: 0xaffa24 v8::internal::V8::FatalProcessOutOfMemory(v8::int ernal::Isolate*, char const*, bool) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 5: 0xef3f32 [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 6: 0xf1b0f1 v8::internal::EvacuateNewSpaceVisitor::Visit(v8:: internal::HeapObject*, int) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 7: 0xf1f137 void v8::internal::LiveObjectVisitor::VisitBlackO bjectsNoFail<v8::internal::EvacuateNewSpaceVisitor, v8::internal::MajorNonAtomicMarkingState>(v8::in ternal::MemoryChunk*, v8::internal::MajorNonAtomicMarkingState*, v8::internal::EvacuateNewSpaceVisit or*, v8::internal::LiveObjectVisitor::IterationMode) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 8: 0xf27df2 v8::internal::FullEvacuator::RawEvacuatePage(v8:: internal::Page*, long*) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 9: 0xf16fb1 v8::internal::Evacuator::EvacuatePage(v8::interna l::Page*) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 10: 0xf172b2 v8::internal::PageEvacuationTask::RunInParallel() [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 11: 0xf0f75f v8::internal::ItemParallelJob::Task::RunInternal( ) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 12: 0xf10297 v8::internal::ItemParallelJob::Run(std::shared_pt r<v8::internal::Counters>) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 13: 0xf1ba6e void v8::internal::MarkCompactCollectorBase::Crea teAndExecuteEvacuationTasks<v8::internal::FullEvacuator, v8::internal::MarkCompactCollector>(v8::int ernal::MarkCompactCollector*, v8::internal::ItemParallelJob*, v8::internal::RecordMigratedSlotVisito r*, v8::internal::MigrationObserver*, long) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 14: 0xf26cfd v8::internal::MarkCompactCollector::EvacuatePages InParallel() [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 15: 0xf26e66 v8::internal::MarkCompactCollector::Evacuate() [i obroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 16: 0xf27902 v8::internal::MarkCompactCollector::CollectGarbag e() [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 17: 0xeff751 v8::internal::Heap::MarkCompact() [iobroker.js-co ntroller] Aug 18 18:36:50 raspberry3 bash[425]: 18: 0xeffe41 v8::internal::Heap::PerformGarbageCollection(v8:: internal::GarbageCollector, v8::GCCallbackFlags) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 19: 0xf00a44 v8::internal::Heap::CollectGarbage(v8::internal:: AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [iobroker.js-controller ] Aug 18 18:36:50 raspberry3 bash[425]: 20: 0xf036b1 v8::internal::Heap::AllocateRawWithRetryOrFail(in t, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 21: 0xeccb34 v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 22: 0x116ccbe v8::internal::Runtime_AllocateInNewSpace(int, v8 ::internal::Object**, v8::internal::Isolate*) [iobroker.js-controller] Aug 18 18:36:50 raspberry3 bash[425]: 23: 0x2454b23dbe1d Aug 18 18:36:50 raspberry3 systemd[1]: iobroker.service: Main process exited, code=killed, status=6/ ABRT

[Apollon77]

Allocation failed sat eindeutig das irgendwas mit ram ist. Und effektiv. Bist du der einzige gerade mit dem Fehler. Nodejs 10.16.2 gibt es erst seit recht kurzem.

Wieviel ram brauchen so die Prozesse die er anmeckert? Das Problem wie oben schon gesagt ist das genau dabei zu erwischen das man Infos sammeln kann.

Mal danach gegoogelt?

[Apollon77]

Ps: kernel mal aktualisiert falls Linux?

[liv-in-sky]

würde gerne mal etwas ausprobieren - es geht um --max-old-space-size=256 - das kommt oft in htop und es gibt viele fehler in google über diesen wert, der meinen ähneln - weißt du wo ich da mal etwas größeres einstellen könnte ? nur zum test

[AlCalzone]

das dürfte in der iobroker.json gehen: https://github.com/ioBroker/ioBroker.js-controller/blob/master/conf/iobroker-dist.json#L3

Danach ioBroker neu starten.

[Apollon77]

Korrekt iobroker.json im iobroker-Data Verzeichnis. Dort in System. Kann es sein das fünfmal wegen dem Memory leas in node <8.15 da einen Wert gesetzt hast und der jetzt zu klein wird?

[liv-in-sky]

ich danke euch - hab es anders gelöst - wollte die proxmox ve eh in einen container wandeln - also alles neu installiert und restore - scheint zu funktionieren

gruß

[psanwald]

Hello, Iam dealing with this error: Caught by controller[0]: FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

In /var/log/syslog I found: Jan 4 10:18:45 host bash[485]: FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory Jan 4 10:19:04 host bash[485]: cat: /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq: Permission denied Jan 4 10:20:04 host bash[485]: cat: /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq: Permission denied Jan 4 10:21:04 host bash[485]: cat: /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq: Permission denied

As far as I understand it, something has no permission on something else... Can I somehow increase the memory for the JavaScript-Engine? The error appears every 2 minutes. Nonetheless, my java scripts seem to work and there are no errors in the protocols. In one script (out of 3) Iam using a cron job for every minute doing queries. Can that cause that problem? Do you have a hint for me?

[Apollon77]

Ok but with this error it seems to be an adapter affected and not the controller. Do check which adapter crashes and open issue there please.

You can use iobroker logfile for this.