Bug in 70_SISPM.pm führt(e) zu Absturz mit Meldung "Out of memory!"

Begonnen von inf0, 28 September 2021, 21:14:32

Vorheriges Thema - Nächstes Thema

inf0

Guten Abend,

nach Wechsel meines Servers von Ubuntu 16.04 auf Ubuntu 18.04 lief FHEM plötzlich nicht mehr.
Den Grund hierfür habe ich gefunden und möchte ihn auf diesem Wege mitteilen, das es notwendig ist, das o.g. Paket zu aktualisieren.

Aber eins nach dem anderen. Wie gesagt, mit 18.04 passierte mir folgendes:
Kurz nach dem Start von FHEM verabschiedete sich das Programm mit folgendem Log-Eintrag:
Out of memory!
Kein Backtrace, kein Hinweis auf die "Problemzone", nichts!
Was macht man in so einem Fall: man googelt. Folgendes habe ich dann gefunden: https://forum.fhem.de/index.php/topic,78327.0.html
Also fluggs meine Perl-Debugger-Kenntnisse von vor 15 Jahren ausgepackt und folgendes herausgefunden: das im Link beschriebene Phänomen reisst fhem.pl irgendwo in der Nähe von Zeile 680 runter.
Um das genauer untersuchen zu können, habe ich dort einen Output des verdächtigen hash-Wertes ins Log eingebaut. Der Output sah dann so aus:
2021.09.27 21:44:52 1: Der hash: 9
2021.09.27 21:44:53 1: Der hash: 61
2021.09.27 21:44:54 1: Der hash: 11
2021.09.27 21:44:55 1: Der hash: 7
2021.09.27 21:44:56 1: Der hash: 13
2021.09.27 21:44:56 1: Der hash: 8
2021.09.27 21:44:57 1: Der hash: 10
2021.09.27 21:44:58 1: Der hash: 49
2021.09.27 21:45:00 1: Der hash: 13
2021.09.27 21:45:01 1: Der hash: 8
2021.09.27 21:45:02 1: Der hash: GLOB(0x564a95e8d770)
Out of memory!


Die dazugehörige modifizierte Code-Stelle:
while (1) {
  my ($rout,$rin, $wout,$win, $eout,$ein) = ('','', '','', '','');
  my $nfound = 0;

  my $timeout = HandleTimeout();

  foreach my $p (keys %selectlist) {
    my $hash = $selectlist{$p};
# Hier hab ich den hash ins Log ausgegeben:
    Log 1, ,,Der hash: $hash->{FD}";
    if(defined($hash->{FD})) {
      vec($rin, $hash->{FD}, 1) = 1


Was man oben erkennen kann: Der hash enthält plötzlich keine fileno mehr, sondern den "file handle", so wie im o.g. Post von werniman beschrieben.

Durch Deaktivieren der SISPM-Einträge in meiner fhem.cfg konnte ich verifizieren, dass es am o.g. Modul lag.

Das Schöne an Perl ist, dass man selber Hand anlegen kann, und deswegen hab ich das Problem tatsächlich auch schon lösen können und zum Modul "$Id: 70_SISPM.pm 21721 2020-04-19 15:35:49Z rudolfkoenig $" ein Diff erzeugt:
227,228c227,229
<   if(defined($hash->{FD})) {
<       close($hash->{FD});
---
>   if(defined($hash->{FH})) {
>       close($hash->{FH});
>       delete $hash->{FH};
266c267,268
<     $hash->{FD}=$FH;
---
>     $hash->{FD}=fileno($FH);
>     $hash->{FH}=$FH;
296c298
<     $FH = $hash->{FD};
---
>     $FH = $hash->{FH};
436a439
> delete $hash->{FH};


Nun freue ich mich auf ein gepatchtes 70_SISPM.pm und darüber, endlich aktiv etwas zum FHEM-Projekt beigetragen haben zu dürfen - auch wenn das Modul vielleicht eher seltener im Einsatz sein dürfte...

Alan

betateilchen

Das Modul wurde seit fast 10 Jahren nicht mehr in seiner Funktionalität gepflegt, ich gehe nicht davon aus, dass sich tatsächlich noch jemand um das Modul kümmert.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

rudolfkoenig

Der Patch ist leider unvollstaendig, patch sagt dazu: "patch: **** unexpected end of file in patch at line 17".
Meines Wissens sind "diff -u" oder "diff -c" bessere Grundlagen, als der nackte diff.

inf0

Hi,

leider konnte ich nicht früher reagieren, da bis jetzt unterwegs.

Also der Patch funktioniert. Hab versucht, die o.a. Fehlermeldung zu reproduzieren. Man muss wirklich alle Zeilen kopieren. Wenn man die letzte Zeile weglässt, dann kommt der o.a. Fehler.

Die letzte Zeile lautet ">    delete $hash->{FH};"

Vielleicht liegt es daran, dass man herunterscrollen muss, um diese Zeile auch noch zu erwischen.

Ich stelle aber gerne auch noch mal das diff -u hier rein:

--- 70_SISPM_orig.pm    2021-09-27 21:24:10.000000000 +0200
+++ 70_SISPM_rep_Alan.pm        2021-09-27 22:04:56.000000000 +0200
@@ -224,8 +224,9 @@
   my @a = split("[ \t][ \t]*", $def);
   my $name = $hash->{NAME};

-  if(defined($hash->{FD})) {
-      close($hash->{FD});
+  if(defined($hash->{FH})) {
+      close($hash->{FH});
+      delete $hash->{FH};
       delete $hash->{FD};
   }
   delete $selectlist{"$name.pipe"};
@@ -263,7 +264,8 @@
        return "SISPM Can't open pipe: $dev: $!";
     }

-    $hash->{FD}=$FH;
+    $hash->{FD}=fileno($FH);
+    $hash->{FH}=$FH;
     $selectlist{"$name.pipe"} = $hash;
     Log 4, "SISPM pipe opened";
     $hash->{STATE} = "running";
@@ -293,7 +295,7 @@
        Log 3, "Oops, SISPM FD empty";
        return undef;
     }
-    $FH = $hash->{FD};
+    $FH = $hash->{FH};

     Log 4, "SISPM reading started";

@@ -434,6 +436,7 @@

     if($eof) {
        close($FH);
+       delete $hash->{FH};
        delete $hash->{FD};
        delete $selectlist{"$name.pipe"};
        InternalTimer(gettimeofday()+ $hash->{Timer}, "SISPM_GetStatus", $hash, 1);


Viel Erfolg und vielen Dank für die schnelle Reaktion.

Alan

Wernieman

Könntest Du es nicht bitte als Datei Anhängen? Macht es Rudi einfacher ....
- Bitte um Input für Output
- When there is a Shell, there is a Way
- Wann war Dein letztes Backup?

Wie man Fragen stellt: https://tty1.net/smart-questions_de.html

rudolfkoenig

Der zweite Patch ist bei mir auch schiefgegangen, habs dann per Hand geaendert und eingecheckt.
Kann bitte jemand Feedback geben?

inf0

Guten Abend,

zur Verifikation Commit 25034 aus SVN runtergeladen und bei mir laufen lassen. Klappt leider nicht. Out of memory!
Ein diff zeigt mir, dass nicht alles übernommen wurde.

Ich versuch's jetzt mal mit den Dateien, so wie Wernieman vorgeschlagen hat.

Hätt ich vielleicht gleich machen sollen.

Sorry für die Mühen. Gottseidank hab ich Newbie-Status   ;)


Alan

rudolfkoenig


inf0

Super, danke. Sieht jetzt perfekt aus.

Schönes Wochenende

Alan