76_SMAInverter.pm - Abfrage von SMA Wechselrichter

[DS_Starter]

Hi Marcel, @ll,

hier ist die Version 2.7  mit der Möglichkeit zur Anzeige der Prozesszeit.
Attribut "showproctime" setzen.
Readings "background_processing_time" und "inverter_processing_time" sind selbsterkärend denke ich.

Grüße
Heiko

[Waldmensch]

Ich denke auch, das der WR einfach nicht schnell genug antwortet. Er bekommt ja pro request 4? Anfragen, die er abarbeiten und beantworten muss. Beim Standard Intervall 60 konnte ich keine Abbrüche feststellen. Auch nicht, als ich 2 Instanzen (mein Altes Modul) parallel laufen hatte. Dritter im Bunde ist bei mir ebenfalls ein SHM. Das Blocking beschleunigt ja nichts, sondern sorgt nur für die Entkopplung von FHEM.

Ein Reading "responsetime" würde in der Tat Sinn machen um da mal Werte zu kriegen. Vielleicht ist das ja sogar von WR zu WR unterschiedlich.


Gesendet von iPhone mit Tapatalk

[Xguide]

Heiko Du bist spitze,
werde es morgen mal einbauen und dann mal gucken was es so ausspuckt.
So sieht es bei genannter Konfiguration aktuell aus:

Code Auswählen Erweitern


2016.12.02 16:27:26 1: Timeout for getstatus_DoParse reached, terminated process 1184
2016.12.02 16:27:26 1: Timeout for getstatus_DoParse reached, terminated process 1185
2016.12.02 17:02:41 1: Timeout for getstatus_DoParse reached, terminated process 3420
2016.12.02 17:37:57 1: Timeout for getstatus_DoParse reached, terminated process 5437
2016.12.02 17:37:57 1: Timeout for getstatus_DoParse reached, terminated process 5438
2016.12.02 18:13:57 1: Timeout for getstatus_DoParse reached, terminated process 7624
2016.12.02 18:13:57 1: Timeout for getstatus_DoParse reached, terminated process 7625
2016.12.02 19:23:42 1: Timeout for getstatus_DoParse reached, terminated process 11752
2016.12.02 19:23:42 1: Timeout for getstatus_DoParse reached, terminated process 11753
2016.12.02 20:01:13 1: Timeout for getstatus_DoParse reached, terminated process 13997
2016.12.02 20:01:13 1: Timeout for getstatus_DoParse reached, terminated process 13998


[DS_Starter]

Hallo,

hier nochmal eine kleine Verbesserung in V2.7.1. 
Die processing_time Readings werden selektiv gelöscht wenn das Attribut "showproctime" nicht mehr gesetzt wird.
In der sleep-Phase trat auch eine "unitialized"-Meldung in der V2.7 auf, die durch die Berechnung der Prozesstime-Readings hervorgerufen wude -> gleich mit gelöst.

@Marcel, mir sieht das recht eigenartig aus dass die Timeouts so gut wie immer gleichzeitig bei beiden WR auftreten. Zumindest wenn ich das richtig in deinem Log interpretiere. Es scheint recht unwahrscheinlich dass beide WR gleichzeitig keine rechtzeitige Antwort senden.
Vorschlag: versuche doch mal in deinem Notify das "get data" eines der beiden WR gegenüber dem anderen zu verzögern (z.B. mit einem nicht blockierenden sleep oder AT).

[Michael]

Moin DS_Starter

Bin mir will das 76_SMAInverter.pm Modul seit gestern Version 2.7.1 und seid heute Version 2.7.2 nicht mehr .
Im Anhang ist ein Log Eintrag.

[DS_Starter]

Sorry hatte nicht exlizit

Code Auswählen Erweitern

use Time::HiRes

geladen. Wahrscheinlich (wie bei mir) wurde es bei dir schon von einem anderen Modul geladen und war nicht aufgefallen.
Jetzt hast du dieses andere vllt. nicht mehr verwendet und nun kam dieser Fehler der die Routine

Undefined subroutine &main::tv_interval called at /opt/fhem//FHEM/76_SMAInverter.pm line 595.

nicht fand.
Anbei die Korrektur V2.7.2

Grüße
Heiko

[Michael]

Vielen Dank !

Läuft wieder, super Arbeit.

[Herjemine]

hmm ich bekomm bei mir aufm PI

Code Auswählen Erweitern


Too many arguments for main::RemoveInternalTimer at ./FHEM/76_SMAInverter.pm line 405, near ""SMAInverter_GetData")"
BEGIN not safe after errors--compilation aborted at ./FHEM/76_SMAInverter.pm line 600.


im Interface wenn ich reload 76_SMAInverter  mache
ist bei der 2.6.1 und bei der V2.7.2

hast Du eine Idee Heiko?

thx
Hermann

[DS_Starter]

Hi Hermann,

ja, -> shutdown restart sollte die richtige Methode sein.

LG
Heiko

[Herjemine]

Hallo Heiko,

nein nicht wirklich, mift 
beim define
kommt Cannot load module SMAInverter
und beim reload das gleiche

Code Auswählen Erweitern


2016.12.03 16:08:05 5: Cmd: >define TriPower SMAInverter xxxx 192.xxx.xxx.xxx<
2016.12.03 16:08:05 5: Loading ./FHEM/76_SMAInverter.pm
2016.12.03 16:08:05 1: reload: Error:Modul 76_SMAInverter deactivated:
Too many arguments for main::RemoveInternalTimer at ./FHEM/76_SMAInverter.pm line 405, near ""SMAInverter_GetData")"
BEGIN not safe after errors--compilation aborted at ./FHEM/76_SMAInverter.pm line 600.

2016.12.03 16:08:05 0: Too many arguments for main::RemoveInternalTimer at ./FHEM/76_SMAInverter.pm line 405, near ""SMAInverter_GetData")"
BEGIN not safe after errors--compilation aborted at ./FHEM/76_SMAInverter.pm line 600.

2016.12.03 16:08:05 4


Gruß
Hermann

[DS_Starter]

Hallo zusammen,

mal so zum Vergleich habe ich die inverter_processing_time ein zeitlang mitgeloggt. Bei mir kommen timeouts sehr selten vor, aber dennoch z.B. am
2016.12.03 13:57:33.

Code Auswählen Erweitern


2016.12.03 13:57:33.469 1: Timeout for getstatus_DoParse reached, terminated process 5876
2016.12.03 13:57:33.470 1: SMAInverter STP_5000 -> BlockingCall getstatus_DoParse timed out


Interessant ist der Vergleich mit dem inverter_processing_time-Logging. Hier ein Auszug:

Code Auswählen Erweitern


2016-12-03_13-46-56__STP_5000__inverter_processing_time    0.3817    2016-12-03 15:38:39 
2016-12-03_13-48-27__STP_5000__inverter_processing_time    0.3634    2016-12-03 15:38:39 
2016-12-03_13-49-58__STP_5000__inverter_processing_time    0.3761    2016-12-03 15:38:39 
2016-12-03_13-51-29__STP_5000__inverter_processing_time    0.3592    2016-12-03 15:38:39 
2016-12-03_13-53-00__STP_5000__inverter_processing_time    0.3702    2016-12-03 15:38:39 
2016-12-03_13-54-31__STP_5000__inverter_processing_time    0.3733    2016-12-03 15:38:39 
2016-12-03_13-56-02__STP_5000__inverter_processing_time    0.3581    2016-12-03 15:38:39 
2016-12-03_13-59-04__STP_5000__inverter_processing_time    0.3718    2016-12-03 15:38:39 
2016-12-03_14-00-35__STP_5000__inverter_processing_time    0.3941    2016-12-03 15:38:39 
2016-12-03_14-02-06__STP_5000__inverter_processing_time    0.3677    2016-12-03 15:38:39 
2016-12-03_14-03-37__STP_5000__inverter_processing_time    0.3814    2016-12-03 15:38:39 
2016-12-03_14-05-08__STP_5000__inverter_processing_time    0.3646    2016-12-03 15:38:39 
2016-12-03_14-06-39__STP_5000__inverter_processing_time    0.3597    2016-12-03 15:38:39 
2016-12-03_14-08-10__STP_5000__inverter_processing_time    0.3969    2016-12-03 15:38:39 
2016-12-03_14-09-41__STP_5000__inverter_processing_time    0.3729    2016-12-03 15:38:39 
2016-12-03_14-11-12__STP_5000__inverter_processing_time    0.3819    2016-12-03 15:38:39


Man sieht deutlich dass der WR im Normalfall knapp 400ms im Background benötigt um zu antworten, hat aber zwischen 2016-12-03_13-56-02 und 2016-12-03_13-59-04
eine Pause eingelegt (ich triggere alle 90s). D.h. der Wert um ca. 2016-12-03_13-57_30 fehlt.
Um diese Zeit hat aber apptime bei mir nicht angeschlagen. So gehe ich davon aus, dass innerhalb FHEM keine Verzögerung stattfand um dies zu beeinflussen.
Momentan vermute ich dass der WR diesen Sendrequest nicht beantwortet, den Request ignoriert, oder FHEM die Antwort nicht erhalten/nicht als solche erkannt hat (timeout steht auf 60s).
Um das weiter zu erforschen würde wahrscheinlich ein Log 5 helfen. Aber da das bei mir so selten auftritt mache ich mir die Mühe erstmal nicht.
Das Ganze soll mal als Vergleich und als Anregung dienen.

Grüße
Heiko

[DS_Starter]

Hallo Hermann,

das würde ja auf einen Syntaxfehler hindeuten was aber eigentlich nicht sein kann da es ja bei mir und bei anderen problemlos läuft.
Es verwundert mich auch der Hinweis auf die Zeile 405, das RemoveInternalTimer ist in Zeile 410.

Kannst du das Modul bei dir mal im Editor öffnen und den Ausschnitt Zeilen 401 bis 416 aus dem Code posten ?

Dein FHEM ist aktuell oder ?  Das funktionsabhängige RemoveInternalTimer gibt es zwar schon eine Weile aber ich glaube erst seit Mitte diesen Jahres.
Bin mir nicht sicher.

EDIT: Gerade nachgeschaut. Das funktionsabhängige "RemoveInternalTimer($hash, "SMAInverter_GetData")" habe ich bereits seit der ersten non-blocking Version drin. Im Prinzip hätte es demnach bei dir immer einen Syntaxfehler geben müssen ... bin einigermaßen verwundert .

Grüße
Heiko

[Herjemine]

ich schau mal nach nem update, fhem kann schon älter sein 

Fhem info:
  Release  : 5.7
  OS       : linux
  Arch     : arm-linux-gnueabihf-thread-multi-64int
  Perl     : v5.14.2

und den SMAInverter hatte ich bisher noch nicht laufen, verwende immer noch spfspot
399-411

Code Auswählen Erweitern


sub SMAInverter_GetData($) {
my ($hash) = @_;
my $name = $hash->{NAME};
my $interval = AttrVal($name, "interval", 60);
my $timeout  = AttrVal($name, "timeout", 60);

RemoveInternalTimer($hash, "SMAInverter_GetData");

if ($init_done != 1) {
     InternalTimer(gettimeofday()+5, "SMAInverter_GetData", $hash, 0);
return;
}



Gruß Hermann

PS auf der Windows Kiste kommt kein Fehler

[DS_Starter]

ich schau mal nach nem update, fhem kann schon älter sein

Jo , mach mal . Dann wird es auch funktionieren 

[Herjemine]

nee ein Update all hat keinen Unterschied gemacht,

seltsam das Release 1.1 von Github funzt