Problem mit Telegrammgenerator

[jonofe]

Hallo zusammen,

ich mal wieder mit einem Problem:

Ich habe ja einen LBS Daemon gebaut, der meine IP Steckdosen einbindet. Funktioniert auch soweit sehr gut. Reaktionszeit <1 Sekunden vom senden des Schalttelegramms am KNX bis zum eigentlich schalten.

Jetzt habe ich 4 1wire Sensoren, die ich minütlich auslesen möchte. Grundsätzlich funktioniert das Auslesen auch sehr gut. Allerdings wenn ich das minütliche Triggern zum Auslesen der Sensoren mit einem Telegrammgenerator mache (Intervall: 60000ms) dann hat das extreme Auswirkungen auf die Performance meines LBS Daemon für die IP Steckdose. Teilweise Schaltzeiten >10 Sekunden. Ich kann im Tracelog sehen, dass der Aufruf des LBS sehr stark verzögert erfolgt. D.h. es scheint nicht an meinem LBS zu liegen, sondern der Aufruf meines LBS scheint nicht mehr schnell genug zu erfolgen. Ich dachte natürlich sofort, dass es am 1wire Baustein liegt, der ja durch den Telegrammgenerator getriggert wird. Doch dort ist der LBS Teil so gut wie leer. Es wird sofort der EXEC Teil aufgerufen. Somit sollte die Logik-Engine ja nicht beeinflusst werden solange der gesamte Rechner keine CPU Probleme hat.

Ich habe dann den Telegrammgenerator durch das System-KO "Trigger-minütlich" ersetzt. Also eigentlich dasselbe Triggerverhalten. Und siehe da, die Performance ist wieder sehr gut. Schaltzeiten < 1Sekunde.

Dann habe ich den Telegrammgenerator wieder eingefügt und, Intervall 60000ms ohne den Ausgang überhaupt mit einem KO zu belegen oder einem Eingang zu verbinden. D.h. er ist einfach nur da und ist mit Trigger=1 aktiviert. Schon habe ich wieder die Performance Probleme in meinem LBS für die IP Steckdosen.

Jetzt bin ich ratlos!
Hat der Telegrammgenerator ein Problem? Hält er irgendwie die Logik auf? Oder mache ich etwas falsch?

Ich bin nicht ganz sicher, aber ich glaube es ist er nach dem Update auf 1.25 aufgetreten.

Hilfe!

[panzaeron]

Hast du versucht den Zyklus mit

setLogicElementStatus($id,1,60000,1); 

direkt im LBS auf eine Minute zu setzen?

[gaert]

Am Telegrammgenerator wurde nichts verändert in 1.24... Was sagt denn die CPU-Last, wenn der TG läuft? Ich kenne deinen LBS nicht, daher kann ich dazu nichts weiter beitragen - aber der EXEC-Teil hat prinzipiell rein garnichts mit anderen LBS am Hut, es sei denn er wird immer wieder aufgerufen

[jonofe]

Was genau macht das?
Meinst du in dem LBS, der vom Telegrammgenerator getriggert wird?
Oder soll ich das anstelle eines Telegrammgenerators verwenden?

[panzaeron]

Wenn du diesen Befehl in einen LBS integrierst, wird er zyklisch (im Beispiel alle 60000ms) aufgerufen und du benötigst den Telegrammgenerator nicht.

[jonofe]

Am Telegrammgenerator wurde nichts verändert in 1.24... Was sagt denn die CPU-Last, wenn der TG läuft? Ich kenne deinen LBS nicht, daher kann ich dazu nichts weiter beitragen - aber der EXEC-Teil hat prinzipiell rein garnichts mit anderen LBS am Hut, es sei denn er wird immer wieder aufgerufen

CPU ist zumindets nicht im roten Bereich.
Ich habe die 1wire Logik noch mal komplett deaktiviert.
Dann eine leere Seite eingefügt und dort einen Telegrammgenerator platziert. E1=1 / E2=1 / E3=60000 / E4=0
Die reine Existenz führt zu extremen Performanceeinbußen in meinem LBS Daemon. Schaltzeiten teilweise >10 Sekunden.

Hier mal der LBS Anteil meines Bausteins. Die eigentliche Ausführung des Bausteins ist performant. Ich kann am Timestamp der ersten DEBUG Ausgabe im Tracelog sehen, das die Ausführung verzögert erfolgt. Und von der ersten DEBUG Ausgabe im LBS-Teil bis zur letzten im EXEC-Bereich, wo die Steckdose geschaltet wird, vergeht weniger als eine Sekunde. Die Verzögerung liegt also scheinbar vor dem Aufruf meines LBS.

function LB_LBSID_debug($id, $msg)
{
    $version = getLogicElementVar($id,4);
    $E=getLogicEingangDataAll($id);
    writeToTraceLog(0,true,$msg.' ('.$E[2]['value'].') [v'.$version.']');
}
    
function LB_LBSID($id) {
    
    $E=getLogicEingangDataAll($id);
       $debug = $E[13]['value'];
    
    $debug && LB_LBSID_debug($id,'mPower-LBS : ###  INFO   ### - mPower LBS started');
    if ($E) {
          if (getLogicElementVar($id,1)!=1) {
            setLogicElementVar($id,1,1);                    
            $uniqid = hexdec(uniqid()); 
            setLogicElementVar($id,3,$uniqid);                    
            callLogicFunctionExec(LBSID,$id);               
           } else { 
            $uniqid = getLogicElementVar($id,3);                    
               $msg_queue = msg_get_queue ( $uniqid );
               for ($i=1; $i<=6; $i++)
             {
                  if ($E[$i+6]['refresh']==1)
                  {
                      $val = $E[$i+6]['value'];
                      msg_send($msg_queue,1,array($i,$val));
                      $debug && LB_LBSID_debug($id,'mPower-LBS : ###  INFO   ### - Sending message to mPower daemon: port/value - '.$i.'/'.$val.' ('.microtime(TRUE).')');
                  }
             }
          }
     }
    $debug && LB_LBSID_debug($id,'mPower-LBS : ###  INFO   ### - mPower LBS finished');
} 

Hier noch ein Tracelog dazu. Das Schaltsignal wurde um "Sat Mar 19 23:14:30 CET 2016" gesendet:

2016-03-19 23_14_40-edomi.feld.home_data_log_TRACELOG.htm_20160319203144.png
Man sieht hier, dass das "mPower LBS started" erst 4 Sekunden im Log später auftaucht und der Rest dann aber in 400ms durchläuft.
Ich hatte zunächst noch den KNX Bus im Verdacht, da EDOMI noch über eibd verbunden ist, allerdings ist das Problem weg, wenn ich den Telegrammgenerator entferne.

hmmmmm ... seltsam ...

[gaert]

Sorry - aber das muss irgendwie an Deinem EXEC-Teil oder was auch immer liegen... Ich habe gerade diverse Telegrammgeneratoren eingefügt und alles verhält sich wie erwartet (allerdings ohne Deinen LBS). Alles andere wäre auch höchst unlogisch, denn der TG kann Dein EXEC-Script nicht beeinflussen - das EXEC-Script läuft ja vollkommen unabhängig vom Rest der Logik. Natürlich kann es prinzipiell zu einem "Telegrammstau" o.d.G. kommen, aber ein nicht konnektierter TG setzt ja garkeine Telegramme ab (und bei 60000ms dürfte es ohnehin keine Probleme in dieser Hinsicht geben).

Die Ursache muss also woanders zu finden sein, ich kann's mir jedenfalls nicht erklären...

[jonofe]

Da geht's dir wie mir
Habe noch mal genauer auf die Last geschaut. Das ganze läuft in einer VM mit einem Core. mysql verbraucht im "top" dauerhaft zwischen 50 und 70%.

und so sieht das in der Übersicht aus:

2016-03-20 00_12_00-EDOMI · Administration.png

Ist das ungesund?

[gaert]

Es ist zumindest merkwürdig (Last)... Es läuft nur 1 LBS, der kann's also eher nicht sein. Aber es laufen mindestens 2 zusätzliche PHP-Prozesse bei Dir (maximal 6 gehören zu EDOMI). Vermutlich EXEC-Scripte? Diese würde ich mir an deiner Stelle mal genauer betrachten...

[jonofe]

Ja, das ist genau der LBS um den es geht. Er prüft ja quasi als Daemon den Status der IP-Steckdose und zwar mit 250ms Wartezeit.
Allerdings habe ich festgestellt, dass ich in jedem Durchlauf die 6x6 Ausgänge, d.h. 36 Ausgänge setze. Jedes setzen ist sicher ein mysql Call, d.h. ca. 150 pro Sekunde . Das erklärt wohl die Last. Allerdings schon komisch, dass es normalerweise ganz gut läuft und bei der Präsenz eines Telegrammgenerators dann ein Problem auftritt.
Werde jetzt erstmal diesen LBS optimieren und dann mal sehn, was der Telegrammgenerator dann sagt.

[wintermute]

Das hilft war vermutlich nicht konkret weiter, aber es liegt nicht generell am TG... ich habe einen hier, der grad alle 2s einen LBS triggert der wiederum einen anderen LBS (mit EXEC triggert) und alles laeuft ruhig und rund.

[jonofe]

Ich denke der EXEC Teil meines LBS ist tatsächlich die Ursache des Problems. Wenn ich die eine Zeile auskommentiere, die in zwei geschachtelten Schleifen die 36 Ausgänge setzt, dann ist die Last okay und auch bei Nutzung des Telegrammgenerators ist kein Performanceeinbruch mehr zu bemerken.
Ich vermute die zu hohe Last auf den mysql löst dann solche seltsamen Effekte aus.

[gaert]

Nicht nur die mySQL-Last ist ggf. etwas hoch für die "Hardware", sondern auch die 36*4=144 gesetzten Ausgänge pro Sekunde(!) sind ein bisschen viel des Guten Falls ich Dich richtig verstanden habe, werden alle 250ms 36 Ausgänge gesetzt... Das landet alles in einer Queue und muss abgearbeitet werden - dies geschieht maximal im etwa 10ms-Takt...

Der Telegrammgenerator (oder jeder andere LBS) setzt nun auch noch irgendwelche KOs, die ebenfalls in der Queue landen. Und/oder er benötigt natürlich auch Ressourcen (mySQL, etc.) - und Dein System läuft ja quasi schon fast am Anschlag...

[jonofe]

Jep, genau so war es . Ich setze jetzt nur noch die 6 Status Ausgänge, d.h. ob die 6 Steckdosen ein oder ausgeschaltet sind. Bei den weiteren 30 Ausgänge berechne ich nun einen Average und sende sie nur noch ca. einmal pro Minute. Damit ist die Last auf 6-10% runter und die Performance der Schaltaktionen ist wieder im Normbereich.
Danke für eure Hinweise bei der Fehlersuche.