Kein Update von Readings, wenn kurz nacheinander gesetzt

[Thorsten Pferdekaemper]

Hi,
ich habe in meinem HM485-Modul das Problem, dass Readings in FHEMWEB nicht geändert werden, wenn ich die schnell nacheinander setze. Etwas seltsam dabei ist, dass ein Schieberegler in der "set-Zeile" gesetzt wird, aber nicht die Werte im Readings-Block.
Ich setze alle Readings per InternalTimer "um 0 Sekunden" verzögert. Das klappt aber nur beim ersten Mal. Wenn ich kurz danach wieder Readings setze, dann muss ich sie etwa um 1 Sekunde verzögern, um die Anzeige in FHEMWEB auf den neusten Stand zu bringen.
Dabei ist es egal, ob ich longpoll 1 oder websocket verwende.
Die Readings werden im Prinzip richtig gesetzt (z.B. in FileLog oder im Event Monitor). Nur FHEMWEB braucht ein Refresh.
Gruß,
   Thorsten

[rudolfkoenig]

Bekommst du alle Events im Event-Monitor oder im telnet "inform timer"?
Was steht in der JavaScript Konsole?

[Thorsten Pferdekaemper]

Hi,
Event Monitor sieht gut aus:

Code Auswählen Erweitern


2017-04-17 19:32:32 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 set_frequency_14948
2017-04-17 19:32:32 HM485 HMW_IO_12_Sw14_DR_MEQ0370289 ACK
2017-04-17 19:32:32 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency: 14948.00
2017-04-17 19:32:32 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency_14948.00

"inform timer" über telnet sieht genauso aus.

JavaScript Konsole (Chrome)

Code Auswählen Erweitern


fhemweb.js:390 19:43:57.660 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07","set_frequency_14690","<div id=\u0022HMW_IO_12_Sw14_DR_MEQ0370289_07\u0022  title=\u0022set_frequ...(199)
fhemweb.js:390 19:43:57.662 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state","set_frequency_14690","set_frequency_14690"]
fhemweb.js:390 19:43:57.662 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state-ts","2017-04-17 19:43:56","2017-04-17 19:43:56"]
Navigated to http://192.168.178.161:8083/fhem?detail=HMW_IO_12_Sw14_DR_MEQ0370289_07&fw_id=
fhemweb.js:390 19:43:58.035 FW_queryValue:{ReadingsVal("HMW_IO_12_Sw14_DR_MEQ0370289_07","frequency","")}
fhemweb.js:390 19:43:58.040 FW_queryValue:{AttrVal("HMW_IO_12_Sw14_DR_MEQ0370289_07","room","")}
fhemweb.js:390 19:43:58.132 Inform-channel opened (HTTP) with filter HMW_IO_12_Sw14_DR_MEQ0370289_07
fhemweb.js:390 19:43:58.157 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07","frequency_14690.00","<div id=\u0022HMW_IO_12_Sw14_DR_MEQ0370289_07\u0022  title=\u0022frequency_...(196)


Gruß,
    Thorsten

[rudolfkoenig]

Kannst du mir bitte noch schreiben, was du in deinem Beispiel erwartest bzw. nicht passiert? Und es waere gut die zum JavaScript gehoerenden Events zu zeigen (will sagen, gleicher Zeitstempel).

Im Event Monitor sehe ich zweimal Statusaenderung fuer HMW_IO_12_Sw14_DR_MEQ0370289_07, einmal fuer
HMW_IO_12_Sw14_DR_MEQ0370289 und einmal frequency Reading fuer .*_07.

Ich habe jetzt dummys mit diesem Namen eingerichtet. Wenn ich sie per

Code Auswählen Erweitern

set HMW_IO_12_Sw14_DR_MEQ0370289_07 set_frequency_14948
set HMW_IO_12_Sw14_DR_MEQ0370289 ACK
setreading HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency 14948.00
set HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency_14948.00
auf einmal aendere, dann kriege ich in der Dateilansicht der .*_07 Geraetes state und frequency mit, auch Device Overview aendert sich.
Das Internal STATE bleibt, das ist aber bekannt.

[Thorsten Pferdekaemper]

Hi,
hier das ganze nochmal mit zusammen passenden Zeitstempeln:

Code Auswählen Erweitern


2017-04-17 20:25:42 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 set_frequency_15206
2017-04-17 20:25:42 HM485 HMW_IO_12_Sw14_DR_MEQ0370289 ACK
2017-04-17 20:25:42 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency: 15206.00
2017-04-17 20:25:42 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency_15206.00


Code Auswählen Erweitern


20:25:43.966 Rcvd:
fhemweb.js:390 20:25:43.966 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07","set_frequency_15206","<div id=\u0022HMW_IO_12_Sw14_DR_MEQ0370289_07\u0022  title=\u0022set_frequ...(199)
fhemweb.js:390 20:25:43.966 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state","set_frequency_15206","set_frequency_15206"]
fhemweb.js:390 20:25:43.966 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state-ts","2017-04-17 20:25:42","2017-04-17 20:25:42"]
Navigated to http://192.168.178.161:8083/fhem?detail=HMW_IO_12_Sw14_DR_MEQ0370289_07&fw_id=
fhemweb.js:390 20:25:44.246 FW_queryValue:{ReadingsVal("HMW_IO_12_Sw14_DR_MEQ0370289_07","frequency","")}
fhemweb.js:390 20:25:44.251 FW_queryValue:{AttrVal("HMW_IO_12_Sw14_DR_MEQ0370289_07","room","")}
fhemweb.js:390 20:25:44.343 Inform-channel opened (HTTP) with filter HMW_IO_12_Sw14_DR_MEQ0370289_07
fhemweb.js:390 20:25:44.368 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07","frequency_15206.00","<div id=\u0022HMW_IO_12_Sw14_DR_MEQ0370289_07\u0022  title=\u0022frequency_...(196)


Was ich erwarte ist folgendes: Das Reading state wird kurz auf "set_frequency_15206" gesetzt. Kurz danach wird das Reading frequency auf "15206.0" und state auf "frequency_15206.0" gesetzt.
Was passiert ist folgendes: Das Reading state wird auf "set_frequency_15206" gesetzt. Das Reading frequency ändert sich gar nicht. Erst bei einem Browser-Refresh werden frequency und state auf die neuen Werte gesetzt.

Es gibt noch einen kleinen Unterschied zwischen Chrome und IE: Das "set frequency" hat einen Slider. In Chrome springt der Slider ganz kurz auf den alten Wert, wenn man "set" drückt, dann aber sofort wieder auf den neuen Wert. Im IE bleibt auch der Slider auf dem alten Wert hängen, bis man ein Browser-Refresh macht.

Sämtliche Readings werden bei mir übrigens per InternalTimer "asynchron" gesetzt. Ich dachte erst, ich hätte das irgendwie falsch gemacht, aber dann würde es ja auch im Event Monitor anders aussehen.

Gruß,
   Thorsten   

[Thorsten Pferdekaemper]

Hi,
ich habe im Modul jetzt die zwei "problematischen" Events um eine Sekunde verzögert. Dann funktioniert das ganze. Hier wieder Events und JavaScript...:

Code Auswählen Erweitern


2017-04-17 20:41:50 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 set_frequency_15206
2017-04-17 20:41:50 HM485 HMW_IO_12_Sw14_DR_MEQ0370289 ACK
2017-04-17 20:41:51 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency: 15206.00
2017-04-17 20:41:51 HM485 HMW_IO_12_Sw14_DR_MEQ0370289_07 frequency_15206.00


Code Auswählen Erweitern


20:41:51.850 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07","set_frequency_15206","<div id=\u0022HMW_IO_12_Sw14_DR_MEQ0370289_07\u0022  title=\u0022set_frequ...(199)
fhemweb.js:390 20:41:51.850 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state","set_frequency_15206","set_frequency_15206"]
:8083/fhem/pgm2/fhemweb.js:390 20:41:51.853 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state-ts","2017-04-17 20:41:50","2017-04-17 20:41:50"]
Navigated to http://192.168.178.161:8083/fhem?detail=HMW_IO_12_Sw14_DR_MEQ0370289_07&fw_id=
fhemweb.js:390 20:41:52.265 FW_queryValue:{ReadingsVal("HMW_IO_12_Sw14_DR_MEQ0370289_07","frequency","")}
fhemweb.js:390 20:41:52.270 FW_queryValue:{AttrVal("HMW_IO_12_Sw14_DR_MEQ0370289_07","room","")}
fhemweb.js:390 20:41:52.358 Inform-channel opened (HTTP) with filter HMW_IO_12_Sw14_DR_MEQ0370289_07
fhemweb.js:390 20:41:52.390 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07","set_frequency_15206","<div id=\u0022HMW_IO_12_Sw14_DR_MEQ0370289_07\u0022  title=\u0022set_frequ...(199)
fhemweb.js:390 20:41:52.961 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07","frequency_15206.00","<div id=\u0022HMW_IO_12_Sw14_DR_MEQ0370289_07\u0022  title=\u0022frequency_...(196)
fhemweb.js:390 20:41:52.977 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-frequency","15206.00","15206.00"]
fhemweb.js:390 20:41:52.977 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-frequency-ts","2017-04-17 20:41:51","2017-04-17 20:41:51"]
fhemweb.js:390 20:41:52.977 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state","frequency_15206.00","frequency_15206.00"]
fhemweb.js:390 20:41:52.977 Rcvd: ["HMW_IO_12_Sw14_DR_MEQ0370289_07-state-ts","2017-04-17 20:41:51","2017-04-17 20:41:51"]

Diese "Lösung" halte ich allerdings für hässlich...

Übrigens werden die beiden letzten Events per readingsBulkUpdate erzeugt.

Gruß,
  Thorsten

[rudolfkoenig]

Ich kann das Problem mit dummies (trotz slider) nicht nachstellen.
Was mich wundert ist dein "Navigated to" Zeile mittendrin: wie loest du das aus? Ich kriege das nicht, bei mir bleibt die Detailseite erhalten. Und: die Timestamps aus dem "Event-Monitor" passen in beiden Faellen nicht zu den Timestamps in der JS Console.

[Thorsten Pferdekaemper]

Ich kann das Problem mit dummies (trotz slider) nicht nachstellen.
Was mich wundert ist dein "Navigated to" Zeile mittendrin: wie loest du das aus?

Keine Ahnung, nach was könnte ich denn da suchen?

Und: die Timestamps aus dem "Event-Monitor" passen in beiden Faellen nicht zu den Timestamps in der JS Console.

Es gehört aber sicherlich zum selben Vorgang. Auf dem System läuft sonst nichts.

Ich werde vielleicht morgen mal versuchen, ein abgespecktes Modul zu schreiben, was das Problem erzeugt. Heute war zu wenig Zeit und zu viel Wein...

Gruß,
    Thorsten

[Thorsten Pferdekaemper]

So, kein Wein mehr im Haus.
Hier ist ein minimales Modul ohne Abhängigkeiten, dass das Problem zeigt:

Code Auswählen Erweitern


package main;

use strict;
use warnings;

sub ThorstensTest_Initialize($);
sub ThorstensTest_Define($$);
sub ThorstensTest_Set($@);


sub ThorstensTest_Initialize($) {
my ($hash) = @_;
$hash->{'DefFn'}          = 'ThorstensTest_Define';
$hash->{'SetFn'}          = 'ThorstensTest_Set';
}


sub ThorstensTest_Define($$) {
return undef;
}


sub ThorstensTest_DoUpdate($) {
my ($params)    = @_;

my $hash    = $params->{hash};
my $value = $params->{value};

readingsBeginUpdate($hash);
    readingsBulkUpdate($hash, "frequency", $value);
readingsBulkUpdate($hash, 'state', "frequency_".$value);
readingsEndUpdate($hash, 1);
}


sub ThorstensTest_Set($@) {
my ($hash, @params) = @_;
my $name  = $params[0];

return '"set ' . $name . '" needs one or more parameter' unless(@params >= 2);

my $cmd   = $params[1];
my $value = $params[2];

# Default set commands for device
my %sets = ('frequency' => "slider,0,1,50000");

    if($cmd eq "frequency") {
my $state = 'set_frequency';
if($value) { $state .= '_'.$value; }
readingsSingleUpdate($hash, "state", $state, 1);
# now simulate that after 100ms the device answers
InternalTimer(gettimeofday() + 0.1, 'ThorstensTest_DoUpdate', {hash => $hash, value => $value}, 1);
return "";
};

# if we reach here, it is either "?" or total rubbish
my $arguments = ' ';
foreach my $arg (sort keys %sets) {
$arguments.= $arg . ($sets{$arg} ? (':' . $sets{$arg}) : '') . ' ';
}
return 'Unknown argument ' . $cmd . ', choose one of ' . $arguments;
}

1;

Bei mir hat das den Dateinamen 10_ThorstensTest.pm.

Dazu ein Device anlegen mit "define bla ThorstensTest" und man kann mit dem Slider rumspielen. Das von mir beschriebene Problem tritt auf.
Wenn man in der Zeile nach "# now simulate that after 100ms the device answers" die 0.1 in eine 1 ändert, dann tritt das Problem nicht mehr auf.

Gruß,
   Thorsten

[rudolfkoenig]

Ist kompliziert.

1. dass set das Neuladen der Seite ausloest, auch wenn ein Reading mit dem gleichen Namen schon angezeigt wird, das ist/war ein Bug, das habe ich aber jetzt gefixt. Hat zur Folge, dass wenn das frequency Reading schon sichtbar ist, dann die Seite nicht neu geladen wird, und alle Readings "richtig" gesetzt werden. Leider keine Internals wie STATE, das koennen wir einfach nicht.

2. Falls kein reading mit dem "set"-Namen auf der Seite gibt, dann wird bei set die Seite neu geladen, und der Status direkt nach dem set wird angezeigt. Es wird zwar ein Refresh vom Status angefordert, aber das ist fuer die Raumansicht "optimiert", und betrifft deswegen nur die oberste Zeile. Wg. irgendein Workaround wird longpoll erst nach 0.1s nach der Seitenaufbau initiiert, also alle Events (bis auf Status, s.o) in dieser Zeit gehen verloren.

=> Eine perfekte Loesung waere Aufwand, ich hoffe dass der Fix aus 1. dir ausreicht.

[Thorsten Pferdekaemper]

Hi,
ich wusste gar nicht, dass ein set in dem Fall ein Neuladen der Seite auslöst. Jedenfalls ist es bei mir schon immer so, dass ich manuell ein Browser-Refresh machen muss, wenn durch ein set (oder auch etwas anderes) ein Reading erst angelegt wird. Kann es sein, dass das daran liegt, dass ich Readings grundsätzlich per InternalTimer setze?
Dass Internals kein automatisches update bekommen ist bekannt und meiner Meinung nach kein Problem.
Ich werde heute Abend oder so den Patch ausprobieren und berichten. Ich denke, dass das vollkommen ausreicht. Normalerweise sind die Readings ja vorhanden.
Ich wundere mich nur etwas über die 0.1 Sekunden. Ich glaube, ich habe 0.2 und 0.5 ausprobiert. Das hat nicht funktioniert. Erst bei 1 Sekunde ging es dann. ...naja, ist aber auch egal, wenn der erste Fall funktioniert.
Gruß,
   Thorsten

[Thorsten Pferdekaemper]

Hi,
ich hab's jetzt getestet. Funktioniert.
Vielen Dank.
Gruß,
    Thorsten