Raspberry Pi: Service stürzt ab bei Neu-Aggregation von Variablen

Hallo Zusammen,

ich versuche, auf meinem Pi 2 (Jessie, aktuelle IPS Version) Energiewerte neu zu aggregieren.

Leider stürzt der Dienst immer wieder mit folgender Symptomatik ab:

  • Anstossen der Neu-Aggregation in der Konsole
  • Einfrieren der Konsole ohne die Meldung „Re-Aggregation gestartet“ („Keine Rückmeldung“)
  • Verbindung zur Kinsole wird unterbrochen
  • Der Dienst auf dem Pi zeigt:
pi@raspberrypi:/media/usbstick $ sudo systemctl status symcon
● symcon.service - LSB: Kurze Beschreibung
   Loaded: loaded (/etc/init.d/symcon)
   Active: active (exited) since Di 2016-01-12 14:59:07 CET; 15min ago
  Process: 1870 ExecStop=/etc/init.d/symcon stop (code=exited, status=0/SUCCESS)
  Process: 1875 ExecStart=/etc/init.d/symcon start (code=exited, status=0/SUCCESS)

Jan 12 14:59:07 raspberrypi symcon[1875]: IP-Symcon started with PID 1881
Jan 12 14:59:07 raspberrypi systemd[1]: Started LSB: Kurze Beschreibung.

Wie immer, bitte ich um zahlreiche Rückmeldungen und Vorschläge :slight_smile:

Gruss aus EU,

Jörg

Bei mir auch so…

Minbian Weezy mit Kernel 4.1.15-v7+ kein Problem bei mir, rennt.
Mein etwas abgeändertes Skript :


<?
/*****
*
* Automatische Reaggregation aller geloggten Variablen
*
* Dieses Skript reaggregiert automatisch alle geloggten Variablen nacheinander
* automatisiert bei Ausführung. Nach Abschluss des Vorgangs wird der Skript-Timer
* gestoppt. Zur erneuten kompletten Reaggregation ist der Inhalt der automatisch
* unterhalb des Skripts angelegten Variable 'History' zu löschen.
*
*****/

$archiveHandlerID = IPS_GetInstanceIDByName("Archive", 0);

$historyID = CreateVariableByName($_IPS['SELF'], "History", 3, "");

// Neu rein, TS
$historyIDdef = CreateVariableByName($_IPS['SELF'], "History defekte ID", 3, "");

// Neu rein ENDE, TS
$finished = true;
$history = explode(',', GetValue($historyID));
// Neu rein, TS
$historydef = explode(',', GetValue($historyIDdef));
// Neu rein ENDE, TS
$variableIDs = IPS_GetVariableList();

foreach ($variableIDs as $variableID)
{
//	 if(IPS_GetVariable($variableID)["VariableValue"]["ValueType"] != 3)
    if(IPS_GetVariable($variableID)["VariableType"] != 3)
    {
        if (AC_GetLoggingStatus($archiveHandlerID, $variableID) && !in_array($variableID,$history))
        {
            $finished = false;
// Neu rein, TS
                $history[] = $variableID;
                SetValue($historyID, implode(',', $history));
// Neu rein Ende, TS
            if (@AC_ReAggregateVariable($archiveHandlerID, $variableID))
            {
// Neu raus, TS
//                $history[] = $variableID;
//                SetValue($historyID, implode(',', $history));
//                print_r ($variableID);
// Neu raus ENDE, TS
            }
// Neu rein, TS
            else
				{
	                $historydef[] = $variableID;
						 SetValue($historyIDdef, implode(',', $historydef));
				}
// Neu rein Ende, TS
            break;
        }
    }
}

if ($finished)
{
    IPS_LogMessage('Reaggregation', 'Reaggregation completed!');
}

IPS_SetScriptTimer($_IPS['SELF'], $finished ? 0 : 2); //zum testen, da schneller auf Odroid....
// IPS_SetScriptTimer($_IPS['SELF'], $finished ? 0 : 60); // Orginal

function CreateVariableByName($id, $name, $type, $profile = "")
{
global $_IPS;
    $vid = @IPS_GetVariableIDByName($name, $id);
    if($vid === false)
    {
		  $vid = IPS_CreateVariable($type);
        IPS_SetParent($vid, $id);
        IPS_SetName($vid, $name);
        IPS_SetInfo($vid, "this variable was created by script #".$_IPS['SELF']);
        if($profile !== "")
        {
            IPS_SetVariableCustomProfile($vid, $profile);
        }
    }
    else
    {
//        SetValue($historyID, "");
//        SetValue($historyIDdef, "");

    }
    return $vid;
}


?>

Keine Ahnung ob das alles noch passt, hatte es mir gleich am Anfang gebastelt, aber es läuft durch …
Muss mich da mal wieder mit beschäftigen, wenn Zeit ist …

Am coolsten wäre, wenn du den Dienst mal damit startest und den Fehler nochmal provozierst: Debugging für Experten

paresy

Hi paresy,

your wish is my command…

Werde ich heute Abend machen.

DANKE!

Sorry, komme erst morgen dazu :frowning:

Guten Morgen,

so: hier ist nun die Ausgabe:



Program terminated with signal SIGKILL, Killed.
The program no longer exists.
(gdb) bt
No stack.
(gdb)

Symcon verhielt sich exakt so, wie im ersten Post beschrieben…

@tomgr: Auch bei der Ausführung Deines Scriptes schmiert der Dienst auf dem Pi ab… Was bedeutet in Deinem Script „defekte ID“??

Gruss aus EU,

Jörg

Öhm. Aber SIGKILL wird nur durch den kill Befehl verursacht. Das ist eine manuelle Einwirkung und kein Absturz.

paresy

Yepp!

Das ist ja das, was mich verwundert!

Ich stosse die Neu-Aggregation an, tue rein gar nichts und SIGKILL ist das Ergebnis…

Frei nach Spoerl: „…ich stehe vor einem Rätsel…“

Linux Kernel so eingestellt, dass ein Prozess bei X MB Ramverbrauch einen KILL bekommt?

paresy

Der Kernel ist „out of the Box“. Raspbian Jessie Light so, wie es zum DL angeboten wird…

Nachtrag:
Wenn die Konsole die Verbindung verliert (weil sich der Service beendet) erscheint: „Die Verbindung wurde erfolgreich beendet.“

„defekte ID“ hatte ich mal eingebaut, da mir das Skript am Anfang auch mal abgeschmiert ist.
Das könnte ich damals dadurch vermeiden.

Guten Morgen,

im Logfile fand ich viele dieser Meldungen:

Invalid data for aggregation year for VariableID #41746. Expected: 1451606400, Found: 1451350800

Kann dies ein Grund für das Abschmieren sein?
Wie kann ich diese Diskrepanz beheben?

Das ist noch der letzte offene Fehler und wird normalerweise durch die Aggregation nach dem Starten gelöst. Kann also leider nicht die Ursache sein.

linux - Who „Killed“ my process and why? - Stack Overflow
Dort wird gesagt, dass ggf. der Arbeitsspeicher aufgebraucht ist, und dann der Kernel den Prozess abschießt. Magst du das mal verifizieren?

Wie groß ist dein db/* Ordner?

paresy

Guten Morgen paresy,

ich habe das mal verifiziert: sieht für mich tatsächlich wie ein Speicherproblem aus:

Jan 15 09:14:37 raspberrypi kernel: [  111.823465] ntpd invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
Jan 15 09:14:37 raspberrypi kernel: [  111.823487] ntpd cpuset=/ mems_allowed=0
Jan 15 09:14:37 raspberrypi kernel: [  111.823514] CPU: 2 PID: 545 Comm: ntpd Not tainted 4.1.13-v7+ #826
Jan 15 09:14:37 raspberrypi kernel: [  111.823521] Hardware name: BCM2709
Jan 15 09:14:37 raspberrypi kernel: [  111.823559] [<80018444>] (unwind_backtrace) from [<80013e08>] (show_stack+0x20/0x24)
Jan 15 09:14:37 raspberrypi kernel: [  111.823579] [<80013e08>] (show_stack) from [<8055a188>] (dump_stack+0x98/0xe0)
Jan 15 09:14:37 raspberrypi kernel: [  111.823595] [<8055a188>] (dump_stack) from [<80557b00>] (dump_header+0xb0/0x1e4)
Jan 15 09:14:37 raspberrypi kernel: [  111.823612] [<80557b00>] (dump_header) from [<800f63c0>] (oom_kill_process+0x200/0x3f0)
Jan 15 09:14:37 raspberrypi kernel: [  111.823628] [<800f63c0>] (oom_kill_process) from [<800f68a4>] (__out_of_memory+0x274/0x380)
Jan 15 09:14:37 raspberrypi kernel: [  111.823642] [<800f68a4>] (__out_of_memory) from [<800f6b48>] (out_of_memory+0x60/0x80)
Jan 15 09:14:37 raspberrypi kernel: [  111.823660] [<800f6b48>] (out_of_memory) from [<800fb43c>] (__alloc_pages_nodemask+0x890/0x8ec)
Jan 15 09:14:37 raspberrypi kernel: [  111.823748] [<800fb43c>] (__alloc_pages_nodemask) from [<800f4ec8>] (filemap_fault+0x220/0x4a8)
Jan 15 09:14:37 raspberrypi kernel: [  111.823768] [<800f4ec8>] (filemap_fault) from [<8011aa54>] (__do_fault+0x4c/0xac)
Jan 15 09:14:37 raspberrypi kernel: [  111.823786] [<8011aa54>] (__do_fault) from [<8011df88>] (handle_mm_fault+0x7d0/0xf90)
Jan 15 09:14:37 raspberrypi kernel: [  111.823804] [<8011df88>] (handle_mm_fault) from [<80560964>] (do_page_fault+0x2dc/0x3f4)
Jan 15 09:14:37 raspberrypi kernel: [  111.823821] [<80560964>] (do_page_fault) from [<800092a8>] (do_PrefetchAbort+0x44/0xa8)
Jan 15 09:14:37 raspberrypi kernel: [  111.823838] [<800092a8>] (do_PrefetchAbort) from [<80560524>] (ret_from_exception+0x0/0x1c)
Jan 15 09:14:37 raspberrypi kernel: [  111.823848] Exception stack(0xb86c7fb0 to 0xb86c7ff8)
Jan 15 09:14:37 raspberrypi kernel: [  111.823861] 7fa0:                                     7ebd3a9c 014aea3c 0000008c 76edaae0
Jan 15 09:14:37 raspberrypi kernel: [  111.823875] 7fc0: 014ae9d0 7ebd3a9c 000dc980 0008e5e8 00000000 00000000 0008e590 000dcde4
Jan 15 09:14:37 raspberrypi kernel: [  111.823887] 7fe0: 000891f4 7ebd3a30 0005dd10 76edaae0 60000010 ffffffff
Jan 15 09:14:37 raspberrypi kernel: [  111.823894] Mem-Info:
Jan 15 09:14:37 raspberrypi kernel: [  111.823917] active_anon:114218 inactive_anon:114245 isolated_anon:0
Jan 15 09:14:37 raspberrypi kernel: [  111.823917]  active_file:88 inactive_file:125 isolated_file:0
Jan 15 09:14:37 raspberrypi kernel: [  111.823917]  unevictable:0 dirty:0 writeback:4 unstable:0
Jan 15 09:14:37 raspberrypi kernel: [  111.823917]  slab_reclaimable:1104 slab_unreclaimable:1644
Jan 15 09:14:37 raspberrypi kernel: [  111.823917]  mapped:269 shmem:149 pagetables:693 bounce:0
Jan 15 09:14:37 raspberrypi kernel: [  111.823917]  free:2039 free_pcp:386 free_cma:0
Jan 15 09:14:37 raspberrypi kernel: [  111.823962] Normal free:8156kB min:8192kB low:10240kB high:12288kB active_anon:456872kB inactive_anon:456980kB active_file:352kB inactive_file:500kB unevictable:0kB isolated(anon):0kB isolated(file$
Jan 15 09:14:37 raspberrypi kernel: [  111.823972] lowmem_reserve[]: 0 0
Jan 15 09:14:37 raspberrypi kernel: [  111.823986] Normal: 20*4kB (EMR) 1*8kB (E) 2*16kB (EM) 1*32kB (U) 0*64kB 1*128kB (R) 1*256kB (R) 1*512kB (R) 1*1024kB (R) 1*2048kB (R) 1*4096kB (R) = 8216kB
Jan 15 09:14:37 raspberrypi kernel: [  111.824058] 521 total pagecache pages
Jan 15 09:14:37 raspberrypi kernel: [  111.824068] 21 pages in swap cache
Jan 15 09:14:37 raspberrypi kernel: [  111.824077] Swap cache stats: add 25695, delete 25674, find 61/84
Jan 15 09:14:37 raspberrypi kernel: [  111.824084] Free swap  = 0kB
Jan 15 09:14:37 raspberrypi kernel: [  111.824090] Total swap = 102396kB
Jan 15 09:14:37 raspberrypi kernel: [  111.824097] 241664 pages RAM
Jan 15 09:14:37 raspberrypi kernel: [  111.824103] 0 pages HighMem/MovableOnly
Jan 15 09:14:37 raspberrypi kernel: [  111.824109] 2589 pages reserved
Jan 15 09:14:37 raspberrypi kernel: [  111.824116] 2048 pages cma reserved
Jan 15 09:14:37 raspberrypi kernel: [  111.824123] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
Jan 15 09:14:37 raspberrypi kernel: [  111.824149] [  110]     0   110     2483      147       6       0       63             0 systemd-journal
Jan 15 09:14:37 raspberrypi kernel: [  111.824164] [  114]     0   114     2831        1       7       0      119         -1000 systemd-udevd
Jan 15 09:14:37 raspberrypi kernel: [  111.824178] [  391]     0   391     1374        1       6       0       50             0 cron
Jan 15 09:14:37 raspberrypi kernel: [  111.824191] [  392]     0   392      845        1       6       0       53             0 systemd-logind
Jan 15 09:14:37 raspberrypi kernel: [  111.824204] [  398]   106   398      964        0       7       0       67             0 avahi-daemon
Jan 15 09:14:37 raspberrypi kernel: [  111.824217] [  400]   105   400     1368        1       6       0       82          -900 dbus-daemon
Jan 15 09:14:37 raspberrypi kernel: [  111.824230] [  425] 65534   425      568        4       6       0       27             0 thd
Jan 15 09:14:37 raspberrypi kernel: [  111.824243] [  434]   106   434      964        0       6       0       56             0 avahi-daemon
Jan 15 09:14:37 raspberrypi kernel: [  111.824257] [  441]     0   441     8031        1      11       0      192             0 rsyslogd
Jan 15 09:14:37 raspberrypi kernel: [  111.824270] [  448]     0   448   331326   227923     561       0    22025             0 symcon
Jan 15 09:14:37 raspberrypi kernel: [  111.824283] [  521]     0   521      637        9       5       0       54             0 dhcpcd
Jan 15 09:14:37 raspberrypi kernel: [  111.824296] [  522]     0   522     1952        1       7       0      114         -1000 sshd
Jan 15 09:14:37 raspberrypi kernel: [  111.824309] [  545]   107   545     1416       29       7       0       77             0 ntpd
Jan 15 09:14:37 raspberrypi kernel: [  111.824322] [  546]     0   546     2817        2       9       0      181             0 sshd
Jan 15 09:14:37 raspberrypi kernel: [  111.824335] [  558]   109   558     3377       63      11       0      366             0 snmpd
Jan 15 09:14:37 raspberrypi kernel: [  111.824348] [  559]     0   559     1127        1       7       0       32             0 agetty
Jan 15 09:14:37 raspberrypi kernel: [  111.824361] [  560]     0   560     1082        1       5       0       32             0 agetty
Jan 15 09:14:37 raspberrypi kernel: [  111.824374] [  577]  1000   577     2817        0       8       0      181             0 sshd
Jan 15 09:14:37 raspberrypi kernel: [  111.824397] Out of memory: Kill process 448 (symcon) score 925 or sacrifice child
Jan 15 09:14:37 raspberrypi kernel: [  111.824416] Killed process 448 (symcon) total-vm:1325304kB, anon-rss:911692kB, file-rss:0kB

Der Ordner db ist 9,8MB gross…

Grüsse aus EU gen Norden,

Jörg

Nachtrag:
Swapsize auf 500MB vergrössern hat insofern geholfen, dass der Kill nun 20s später auftaucht.
Mit top ist klar zu erkennen, wie beim Reaggregieren erst das RAM, dann der Swap-Memory aufgefressen wird…

Magst du mir mal dein komplettes Projekt (/usr/share/symcon) zippen und an office@symcon.de schicken?

paresy

Hallo Paresy,

bei mir stürzt Ip-Symcon auch mit der neuen Funktion im Archive ab.

Sobald ich die Frage nach Reaggregation mit ja freigebe ist ende im Gelände.

Symcon 4.0 aktuelle Version auf Pi 2 1MB

Im Anhang die Message Datei.

Jan 17 10:54:42 raspberrypi kernel: [924691.501939] symcon invoked oom-killer: gfp_mask=0x200da, order=0, oom_score_adj=0
Jan 17 10:54:42 raspberrypi kernel: [924691.501962] symcon cpuset=/ mems_allowed=0
Jan 17 10:54:42 raspberrypi kernel: [924691.501990] CPU: 3 PID: 11252 Comm: symcon Not tainted 4.1.13-v7+ #826
Jan 17 10:54:42 raspberrypi kernel: [924691.501997] Hardware name: BCM2709
Jan 17 10:54:42 raspberrypi kernel: [924691.502037] [<80018444>] (unwind_backtrace) from [<80013e08>] (show_stack+0x20/0x24)
Jan 17 10:54:42 raspberrypi kernel: [924691.502057] [<80013e08>] (show_stack) from [<8055a188>] (dump_stack+0x98/0xe0)
Jan 17 10:54:42 raspberrypi kernel: [924691.502073] [<8055a188>] (dump_stack) from [<80557b00>] (dump_header+0xb0/0x1e4)
Jan 17 10:54:42 raspberrypi kernel: [924691.502090] [<80557b00>] (dump_header) from [<800f63c0>] (oom_kill_process+0x200/0x3f0)
Jan 17 10:54:42 raspberrypi kernel: [924691.502106] [<800f63c0>] (oom_kill_process) from [<800f68a4>] (__out_of_memory+0x274/0x380)
Jan 17 10:54:42 raspberrypi kernel: [924691.502121] [<800f68a4>] (__out_of_memory) from [<800f6b48>] (out_of_memory+0x60/0x80)
Jan 17 10:54:42 raspberrypi kernel: [924691.502138] [<800f6b48>] (out_of_memory) from [<800fb43c>] (__alloc_pages_nodemask+0x890/0x8ec)
Jan 17 10:54:42 raspberrypi kernel: [924691.502157] [<800fb43c>] (__alloc_pages_nodemask) from [<8011e370>] (handle_mm_fault+0xbb8/0xf90)
Jan 17 10:54:42 raspberrypi kernel: [924691.502177] [<8011e370>] (handle_mm_fault) from [<80560964>] (do_page_fault+0x2dc/0x3f4)
Jan 17 10:54:42 raspberrypi kernel: [924691.502194] [<80560964>] (do_page_fault) from [<800091e4>] (do_DataAbort+0x44/0xc4)
Jan 17 10:54:42 raspberrypi kernel: [924691.502211] [<800091e4>] (do_DataAbort) from [<805601e4>] (__dabt_usr+0x44/0x60)
Jan 17 10:54:42 raspberrypi kernel: [924691.502220] Exception stack(0xb5e5ffb0 to 0xb5e5fff8)
Jan 17 10:54:42 raspberrypi kernel: [924691.502233] ffa0: 00000031 00000035 27825ff0 00000fe1
Jan 17 10:54:42 raspberrypi kernel: [924691.502247] ffc0: 27825ff8 6ff00010 370e0000 27826020 00026000 00000028 00000040 27800000
Jan 17 10:54:42 raspberrypi kernel: [924691.502259] ffe0: 36123000 601fe690 767c3064 767c2f18 80000010 ffffffff
Jan 17 10:54:42 raspberrypi kernel: [924691.502267] Mem-Info:
Jan 17 10:54:42 raspberrypi kernel: [924691.502289] active_anon:113060 inactive_anon:113112 isolated_anon:0
Jan 17 10:54:42 raspberrypi kernel: [924691.502289] active_file:130 inactive_file:156 isolated_file:0
Jan 17 10:54:42 raspberrypi kernel: [924691.502289] unevictable:0 dirty:0 writeback:2453 unstable:0
Jan 17 10:54:42 raspberrypi kernel: [924691.502289] slab_reclaimable:1998 slab_unreclaimable:2423
Jan 17 10:54:42 raspberrypi kernel: [924691.502289] mapped:396 shmem:311 pagetables:1138 bounce:0
Jan 17 10:54:42 raspberrypi kernel: [924691.502289] free:2047 free_pcp:324 free_cma:0
Jan 17 10:54:42 raspberrypi kernel: [924691.502337] Normal free:8188kB min:8192kB low:10240kB high:12288kB active_anon:452240kB inactive_anon:452448kB active_file:520kB inactive_file:624kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:966656kB managed:948108kB mlocked:0kB dirty:0kB writeback:9812kB mapped:1584kB shmem:1244kB slab_reclaimable:7992kB slab_unreclaimable:9692kB kernel_stack:1624kB pagetables:4552kB unstable:0kB bounce:0kB free_pcp:1296kB local_pcp:144kB free_cma:0kB writeback_tmp:0kB pages_scanned:75656 all_unreclaimable? yes
Jan 17 10:54:42 raspberrypi kernel: [924691.502346] lowmem_reserve: 0 0
Jan 17 10:54:42 raspberrypi kernel: [924691.502360] Normal: 314kB (UE) 08kB 116kB ® 132kB ® 064kB 1128kB ® 1256kB ® 1512kB ® 11024kB ® 12048kB ® 1*4096kB ® = 8236kB
Jan 17 10:54:42 raspberrypi kernel: [924691.502431] 3129 total pagecache pages
Jan 17 10:54:42 raspberrypi kernel: [924691.502441] 2507 pages in swap cache
Jan 17 10:54:42 raspberrypi kernel: [924691.502450] Swap cache stats: add 78289, delete 75782, find 556090/558741
Jan 17 10:54:42 raspberrypi kernel: [924691.502457] Free swap = 0kB
Jan 17 10:54:42 raspberrypi kernel: [924691.502463] Total swap = 102396kB
Jan 17 10:54:42 raspberrypi kernel: [924691.502470] 241664 pages RAM
Jan 17 10:54:42 raspberrypi kernel: [924691.502476] 0 pages HighMem/MovableOnly
Jan 17 10:54:42 raspberrypi kernel: [924691.502482] 2589 pages reserved
Jan 17 10:54:42 raspberrypi kernel: [924691.502489] 2048 pages cma reserved

Aloha paresy,

ich hatte am Freitag mein Projekt per Mail übermittelt.

Gibt es schon neue Erkenntnisse?

Gruss aus EU,

Jörg

Guten Morgen,

habe das Swap-File auf dem Raspi erst auf 500MB, dann auf 1GB vergrössert.

Immer noch das gleiche Phänomen: erst wird der RAM aufgefressen, danach ist das Swapfile dran. Letztendlich wird dann der symcon-Service graceful beendet…

Gruss aus EU,

Jörg

Bin noch dran :slight_smile:

paresy