[gefixed] Heutiges CUL_HM update defekt

Beta-User · 21 Februar 2019, 14:53:12

@Wzut: Danke für die Erläuterung. Gibt es dazu einen bestimmten Timeout? Zufällig ca. eine halbe Stunde? Das spräche für einen ziemlich eindeutigen Verursacher in Zeile 10000, der logauszug war nur vorne und hinten abgeschnitten, aber ansonsten an der Stelle ungekürzt:

Code Auswählen

Can't use string ("65") as an ARRAY ref while "strict refs" in use at ./FHEM/10_CUL_HM.pm line 10000.
Selstam ist nur, dass ich ein paar manuelle Schaltvorgänge testweise via FHEMWEB abgesetzt hatte, was offensichtlich auch funktioniert hat. Der fragliche war nur der letzte.

Das letzte, was ich in FHEMWEB wahrgenommen hatte, war, dass der Slider auf "on" bzw. 100% gesprungen ist; daher war ich auch zunächst davon ausgegangen, dass alles ok ist. Den Auslöser würde ich daher erst mal in der Verarbeitungslogik der Rückmeldung vom Aktor suchen.

Ergänzende Info: Es steht eine VCCU dahinter, schnellstes IO ist in der Regel ein Pi-PCB@USB (HMUARTLGW), es gibt noch einen CUL und einen Maple mit einem Transceiver im HM-Modus (der ist via LAN angebunden und typischerweise das letzte IO, das die Rückmeldung an den Server liefert). Auf dem Maple wird der erste Transceiver für HM genutzt, die anderen werden mit STACKABLE angesprochen.

helmut · 21 Februar 2019, 17:02:29

Zitat von: martinp876 am 21 Februar 2019, 08:15:39
Keine Tester? Bei mir läuft es nun schon ein paar Wochen. Keine Probleme.

Das kann ich bestaetigen. Laeuft auch bei mir stabil und ohne Fehlermeldungen,
wenn auch ohne SIP-Modul mit dem aktuellen Stand:

Code Auswählen

File            Rev   Last Change 
10_CUL_HM.pm    18184 2019-01-08 20:43:59Z martinp876 
98_HMinfo.pm    17838 2018-11-25 10:51:09Z martinp876 
00_HMUARTLGW.pm 16166 2018-02-13 19:52:08Z mgernoth 
HMConfig.pm     18284 2019-01-16 18:56:58Z martinp876

Gruss Helmut

Beta-User · 21 Februar 2019, 17:27:09

@helmut:
Ist das die Test-Version hier aus #168 oder die aus dem normalen update?
ID und Zeitstempel sind bei beiden scheinbar gleich (und die regulär verteilte funktioniert auch mit SIP bei mir bis dato gut - außerdem hat Wzut ja erläutert, dass es vermutlich nicht daran lag...)

Das mit der halben Stunde paßt allerdings recht gut auf den Aufruf in Zeile 9992 (alt: 9692), und genau an der Stelle (Zeile 10000 neu) gab es auch größere Änderungen im Code.

Als Hardwarebasis nutze ich btw. einen Atom single-Core mit Debian, Perl-Version kann ich bei Bedarf nachliefern.

Wzut · 21 Februar 2019, 17:58:30

Zitat von: Beta-User am 21 Februar 2019, 14:53:12
Gibt es dazu einen bestimmten Timeout?

Nun beim ausgehendem Ruf gibst du ja den Timeout selbst im Set Kommando mit an,
beim listen_mode gibt es bei erfolgreichem register am SIP Server keinen, da man ja keine Ahnung hat wann das nächste mal jemand anruft

helmut · 21 Februar 2019, 19:29:43

Zitat von: Beta-User am 21 Februar 2019, 17:27:09
@helmut:
Ist das die Test-Version hier aus #168 oder die aus dem normalen update?

Das ist die aus dem normalen Update.

Gruss Helmut

hoppel118 · 21 Februar 2019, 19:32:18

Zitat von: Beta-User am 21 Februar 2019, 13:04:15
Gemeint war die, die man mit dem update erhält. (Der Weg ist Entwickler läd ins svn, der Stand um kurz vor 8:00 Uhr geht ins update, individuelles FHEM holt sich, was neu ist; dabei müßte der Zeitstemple der Datei entscheidend sein).

OK, dann habe ich die Datei bei mir am Laufen, die im SVN ist. Mein System läuft übrigens seit heute Mittag ohne Probleme. Falls es was neues zum Testen gibt, bin ich gern wieder dabei. Habe immer ein Backup, es kann also nichts schief gehen, toi, toi, toi.

Zitat von: Beta-User am 21 Februar 2019, 13:04:15
Das Log bleibt erhalten. Kannst also auch jetzt noch schauen, was um die Zeit des Absturzes rum passiert ist, auch ohne das nochmal zu provozieren.

Entscheidend sind die Zeilen vor "Server started...." (da gibt es einige Zeilen davor, die zeitlich dem Neustart zuzuordnen sind; die sind noch uninteressant;...).

Redest du jetzt vom FHEM-log? Das bleibt bei mir nicht erhalten, um 10:50 hatte ich FHEM nach dem Update gestartet und um 11:20 Uhr ist FHEM dann abgestürzt. Folgender Auszug aus dem Log:

Code Auswählen

2019.02.20 08:30:39 3: Roborock: initialized
2019.02.21 10:39:06 2: Backup with command: tar -cf - "./certs" "./CHANGED" "./configDB.pm" "./contrib" "./demolog" "./docs" "./FHEM" "./fhem-5.8.deb" "./fhem.cfg" "./fhem.cfg.backup" "./fhem.cfg.CUL_HM" "./fhem.cfg.demo" "./fhem.cfg.save" "./fhem.pl" "./log" "./MAINTAINER.txt" "./README_DEMO.txt" "./restoreDir" "./unused" "./www" |gzip > ./backup/FHEM-20190221_103906.tar.gz
2019.02.21 12:02:31 1: Including fhem.cfg
2019.02.21 12:02:31 3: telnetPort: port 7072 opened
2019.02.21 12:02:31 3: WEB: port 8083 opened
2019.02.21 12:02:31 3: WEBphone: port 8084 opened

Falls du das syslog meinst. Dort finde ich an den entscheidenden Stellen auch nicht wirklich etwas. Zwischendurch werden nur generelle Sachen der Homebrdige und des Systems allgemein geloggt...

Code Auswählen

Feb 21 10:40:30 omv4 systemd[1]: Stopping Node.js Homebridge Service...
Feb 21 10:40:30 omv4 homebridge[1542]: [2019-2-21 10:40:30] Got SIGTERM, shutting down Homebridge...
Feb 21 10:40:35 omv4 systemd[1]: homebridge-homematic.service: Main process exited, code=exited, status=143/n/a
Feb 21 10:40:35 omv4 systemd[1]: Stopped Node.js Homebridge Service.
Feb 21 10:40:35 omv4 systemd[1]: homebridge-homematic.service: Unit entered failed state.
Feb 21 10:40:35 omv4 systemd[1]: homebridge-homematic.service: Failed with result 'exit-code'.
Feb 21 10:40:38 omv4 systemd[1]: Stopping Node.js Homebridge Service...
Feb 21 10:40:38 omv4 homebridge[1590]: [2019-2-21 10:40:38] Got SIGTERM, shutting down Homebridge...
Feb 21 10:40:44 omv4 systemd[1]: homebridge-hue.service: Main process exited, code=exited, status=143/n/a
Feb 21 10:40:44 omv4 systemd[1]: Stopped Node.js Homebridge Service.
Feb 21 10:40:44 omv4 systemd[1]: homebridge-hue.service: Unit entered failed state.
Feb 21 10:40:44 omv4 systemd[1]: homebridge-hue.service: Failed with result 'exit-code'.
Feb 21 10:40:48 omv4 systemd[1]: Stopping Node.js Homebridge Service...
Feb 21 10:40:48 omv4 homebridge[1627]: [2019-2-21 10:40:48] Got SIGTERM, shutting down Homebridge...
Feb 21 10:40:53 omv4 systemd[1]: homebridge-xiaomi.service: Main process exited, code=exited, status=143/n/a
Feb 21 10:40:53 omv4 systemd[1]: Stopped Node.js Homebridge Service.
Feb 21 10:40:53 omv4 systemd[1]: homebridge-xiaomi.service: Unit entered failed state.
Feb 21 10:40:53 omv4 systemd[1]: homebridge-xiaomi.service: Failed with result 'exit-code'.
Feb 21 10:41:08 omv4 systemd[1]: Stopping FHEM Home Automation...
Feb 21 10:41:08 omv4 systemd[1]: Stopped FHEM Home Automation.
Feb 21 10:48:16 omv4 systemd[1]: Stopping FHEM Home Automation...
Feb 21 10:48:16 omv4 systemd[1]: Stopped FHEM Home Automation.
Feb 21 10:50:43 omv4 systemd[1]: Starting FHEM Home Automation...
Feb 21 10:50:43 omv4 systemd[1]: Started FHEM Home Automation.
Feb 21 11:09:01 omv4 CRON[2940]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Feb 21 11:09:04 omv4 systemd[1]: Starting Clean php session files...
Feb 21 11:09:04 omv4 systemd[1]: Started Clean php session files.
Feb 21 11:17:01 omv4 CRON[3734]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Feb 21 11:17:19 omv4 homebridge[424]:   2019-02-21 11:17:19 caching: OG_WZ_Essbereich_Thermostat_Clima-measured-temp: 20.2
Feb 21 11:17:19 omv4 homebridge[424]: [2019-2-21 11:17:19] [FHEM]     caching: CurrentTemperature: 20.2 (as number; from '20.2')
Feb 21 11:17:19 omv4 homebridge[424]: [2019-2-21 11:17:19] [FHEM]       adding history entry { time: 1550744239,
Feb 21 11:17:19 omv4 homebridge[424]:   setTemp: 18,
Feb 21 11:17:19 omv4 homebridge[424]:   currentTemp: 20.2,
Feb 21 11:17:19 omv4 homebridge[424]:   valvePosition: 0 }
Feb 21 11:17:58 omv4 homebridge[424]:   2019-02-21 11:17:58 caching: OG2_Dachboden_Strom_Server_Pwr-current: 479
Feb 21 11:17:58 omv4 homebridge[424]: [2019-2-21 11:17:58] [FHEM]     caching: Custom Current: 0.47900000000000004 (as number; from '479')
Feb 21 11:17:58 omv4 homebridge[424]:   2019-02-21 11:17:58 caching: OG2_Dachboden_Strom_Server_Pwr-energy: 10951.6
Feb 21 11:17:58 omv4 homebridge[424]: [2019-2-21 11:17:58] [FHEM]     caching: Custom Energy: 10.951600000000001 (as number; from '10951.6')
Feb 21 11:17:58 omv4 homebridge[424]:   2019-02-21 11:17:58 caching: OG2_Dachboden_Strom_Server_Pwr-power: 95.6
Feb 21 11:17:58 omv4 homebridge[424]: [2019-2-21 11:17:58] [FHEM]     caching: Custom Power: 95.6 (as number; from '95.6')
Feb 21 11:17:58 omv4 homebridge[424]: [2019-2-21 11:17:58] [FHEM]       adding history entry { time: 1550744278, power: 95.6 }
Feb 21 11:17:58 omv4 homebridge[424]:   2019-02-21 11:17:58 caching: OG2_Dachboden_Strom_Server_Pwr-voltage: 233.4
Feb 21 11:17:58 omv4 homebridge[424]: [2019-2-21 11:17:58] [FHEM]     caching: Custom Voltage: 233.4 (as number; from '233.4')
Feb 21 11:19:59 omv4 homebridge[424]:   2019-02-21 11:19:59 caching: OG2_Dachboden_Strom_Server_Pwr-current: 482
Feb 21 11:19:59 omv4 homebridge[424]: [2019-2-21 11:19:59] [FHEM]     caching: Custom Current: 0.482 (as number; from '482')
Feb 21 11:19:59 omv4 homebridge[424]:   2019-02-21 11:19:59 caching: OG2_Dachboden_Strom_Server_Pwr-energy: 10954.8
Feb 21 11:19:59 omv4 homebridge[424]: [2019-2-21 11:19:59] [FHEM]     caching: Custom Energy: 10.954799999999999 (as number; from '10954.8')
Feb 21 11:19:59 omv4 homebridge[424]:   2019-02-21 11:19:59 caching: OG2_Dachboden_Strom_Server_Pwr-power: 95.84
Feb 21 11:19:59 omv4 homebridge[424]: [2019-2-21 11:19:59] [FHEM]     caching: Custom Power: 95.84 (as number; from '95.84')
Feb 21 11:19:59 omv4 homebridge[424]: [2019-2-21 11:19:59] [FHEM]       adding history entry { time: 1550744399, power: 95.84 }
Feb 21 11:19:59 omv4 homebridge[424]:   2019-02-21 11:19:59 caching: OG2_Dachboden_Strom_Server_Pwr-voltage: 232
Feb 21 11:19:59 omv4 homebridge[424]: [2019-2-21 11:19:59] [FHEM]     caching: Custom Voltage: 232 (as number; from '232')
Feb 21 11:20:30 omv4 homebridge[424]:   2019-02-21 11:20:30 caching: Aussen_Nord_Sensor-temperature: 7.5
Feb 21 11:20:30 omv4 homebridge[424]: [2019-2-21 11:20:30] [FHEM]     caching: CurrentTemperature: 7.5 (as number; from '7.5')
Feb 21 11:20:30 omv4 homebridge[424]: [2019-2-21 11:20:30] [FHEM]       adding history entry { time: 1550744430, temp: 7.5 }
Feb 21 11:20:44 omv4 homebridge[461]: longpoll ended, reconnect in: 200msec
Feb 21 11:20:44 omv4 homebridge[424]: longpoll ended, reconnect in: 200msec
Feb 21 11:20:44 omv4 homebridge[496]: longpoll ended, reconnect in: 200msec
Feb 21 11:20:44 omv4 systemd[1]: fhem.service: Main process exited, code=exited, status=255/n/a
Feb 21 11:20:44 omv4 systemd[1]: fhem.service: Unit entered failed state.
Feb 21 11:20:44 omv4 systemd[1]: fhem.service: Failed with result 'exit-code'.
Feb 21 11:20:44 omv4 homebridge[461]: starting longpoll: https://127.0.0.1:8083/fhem?XHR=1&inform=type=status;addglobal=1;filter=.*;since=1550742989.392;fmt=JSON&timestamp=1550744444408
Feb 21 11:20:44 omv4 homebridge[496]: starting longpoll: https://127.0.0.1:8083/fhem?XHR=1&inform=type=status;addglobal=1;filter=.*;since=1550744164.486;fmt=JSON&timestamp=1550744444409
Feb 21 11:20:44 omv4 homebridge[424]: starting longpoll: https://127.0.0.1:8083/fhem?XHR=1&inform=type=status;addglobal=1;filter=.*;since=1550744434.667;fmt=JSON&timestamp=1550744444409
Feb 21 11:20:44 omv4 homebridge[461]: longpoll error: Error: connect ECONNREFUSED 127.0.0.1:8083, retry in: 10000msec
Feb 21 11:20:44 omv4 homebridge[496]: longpoll error: Error: connect ECONNREFUSED 127.0.0.1:8083, retry in: 10000msec
Feb 21 11:20:44 omv4 homebridge[424]: longpoll error: Error: connect ECONNREFUSED 127.0.0.1:8083, retry in: 10000msec
Feb 21 11:20:54 omv4 homebridge[461]: starting longpoll: https://127.0.0.1:8083/fhem?XHR=1&inform=type=status;addglobal=1;filter=.*;since=1550742989.392;fmt=JSON&timestamp=1550744454415
Feb 21 11:20:54 omv4 homebridge[496]: starting longpoll: https://127.0.0.1:8083/fhem?XHR=1&inform=type=status;addglobal=1;filter=.*;since=1550744164.486;fmt=JSON&timestamp=1550744454416
Feb 21 11:20:54 omv4 homebridge[424]: starting longpoll: https://127.0.0.1:8083/fhem?XHR=1&inform=type=status;addglobal=1;filter=.*;since=1550744434.667;fmt=JSON&timestamp=1550744454416
Feb 21 11:20:54 omv4 homebridge[461]: longpoll error: Error: connect ECONNREFUSED 127.0.0.1:8083, retry in: 15000msec
Feb 21 11:20:54 omv4 homebridge[496]: longpoll error: Error: connect ECONNREFUSED 127.0.0.1:8083, retry in: 15000msec
Feb 21 11:20:54 omv4 homebridge[424]: longpoll error: Error: connect ECONNREFUSED 127.0.0.1:8083, retry in: 15000msec

Zitat von: Beta-User am 21 Februar 2019, 13:04:15
du solltest dich allg. mal mit deinem log beschäftigen, da stehen oft "interessante" Sachen drin

Warum dekst du, dass ich das nicht tue? Ich beschäftige mich ziemlich häufig mit meinem Log.

Zitat von: Beta-User am 21 Februar 2019, 13:04:15
Wenn du mehr zur Absturzursache wissen wolltest, wäre stacktrace das Stichwort (habe ich aber bisher auch nicht genutzt). Würde aber mal auf Martin warten, ob der schon eine Idee hat oder das anfordert (dann mache ich auch gerne die Premiere).

OK, ich warte auf Martin.

Schönen Abend noch in die Runde!

Gruß Hoppel

hoppel118 · 21 Februar 2019, 19:36:03

Zitat von: helmut am 21 Februar 2019, 19:29:43
Das ist die aus dem normalen Update.

Das ist leider nicht die Version, um die es hier geht. Meinem Verständnis nach sind die Änderungen, die die Probleme ursprünglich mal verursacht haben, im svn zurückgezogen worden. In Post ~~168~~ 167 wurde die zu testende Version des Moduls gepostet.

Gruß Hoppel

helmut · 21 Februar 2019, 20:02:19

Zitat von: hoppel118 am 21 Februar 2019, 19:36:03
Das ist leider nicht die Version, um die es hier geht.

Du hast recht. Das hatte ich uebersehen. Wenn ich am SO Zeit finde, teste ich die aus Post 167 mal.

Gruss Helmut

Beta-User · 21 Februar 2019, 21:07:50

Das mit der Zählweise ist schon seltsam, kommt wohl darauf an, wierum man die Beiträge anzeigt (hier: neuster oben =168).

Für mich klingt das danach, dass da ein paar statusRequest-timeouts ablaufen, ohne dass Rückmeldung erfolgt ist (habe hier einige Türkontakte, die sich nach 1800 sec. typischerweise noch nicht gemeldet haben).

Wie dem auch sei, gemeint war das FHEM-log, und das ist bei dir auch sowas von unauffällig. Nicht mal der Zeile 10.000-Hinweis... (Das mit dem log-Hinweis war dadurch motiviert, dass nur der systemctl-Auszug da war, aber nicht das FHEM-log, und das ist bei Abstürzen eigentlich immer das erste, was man sich ansehen sollte. Nix für ungut...).

@Martin: kurze Rückmeldung wäre nett, ob noch Infos benötigt werdnen
Meine Perl-Version btw.: v5.26.1 built for x86_64-linux-gnu-thread-multi

martinp876 · 23 Februar 2019, 09:33:42

Sorry, meine antwort habe ich wohl nicht abgeschickt.
Ich vermute das Problem bei den berechnungen welche zu einem vereinfachten peering Kommando führen sollen. ist in der version eingebaut aber nicht sichtbar. Die pauschale Fehlermeldung deutet auf ein Speicher Problem oder etwas ähnliches hin.
Ich werde heute abend den Code deaktivieren und eine neue version einstellen.

martinp876 · 24 Februar 2019, 10:35:29

sorry, dummer fehler. Hätte ich finden müssen.

hat nichts mit der Umstellung auf mId zu tun. Anbei der Fix (eine Kleinigkeit - mit Wirkung

Beta-User · 24 Februar 2019, 12:51:14

Thx. Version von heute morgen läuft seit mehr als 2,5h ohne Absturz

.

Otto123 · 25 Februar 2019, 10:39:26

Moin,

mein Test läuft jetzt auch. Ich war etwas zögerlich

Um eine schnelle Rückkehr zur ermöglichen, habe ich mal ein extra savepm Kommando gebaut. Damit sichert man die bestehende Moduldatei

Code Auswählen

savepm 10_CUL_HM.pm
Im Fehlerfall kann man relativ schnell über restore den alten Modulstand wiederherstellen.

Code Auswählen

restore list pm/zeigt die verfügbaren Stände

Code Auswählen

restore pm/YYYY-MM-DDholt den gesicherten Stand zurück. Da alles unter fhem passiert hat man keinen trouble mit Berechtigung.
Hier das define für das Kommando, den Rumpf habe ich hier bei Dan geklaut.

Code Auswählen

define c2 cmdalias savepm .* AS {\
  my ($e,$g) = (undef,(split(" ",$EVENT))[0]);;\
  if (defined $g)\
  {\
    $e = qx(mkdir -p ./restoreDir/pm/"$year-$month-$mday"/FHEM/);;\
    $e = qx(cp ./FHEM/$g ./restoreDir/pm/"$year-$month-$mday"/FHEM/)\
  } else {\
    $e = "use savepm Filename inside ./FHEM/"\
  }\
  return $e ? $e : "done"\
}

Gruß Otto

Beta-User · 25 Februar 2019, 13:34:21

Kurze Zwischeninfo: Lief bis heute Mittag problemfrei.

Da ich ganz sicher gehen wollte, dass ich auch wirklich mit der Version hier unterwegs bin (ich hatte das nach dem Reinkopieren des neuen Codes nur über reload gemacht), habe ich vorhin doch nochmal FHEM neu gestartet. Läuft wieder seit mehr als 1800 Sekunden

. (@Martin, kleine Anregung: ich hatte das gestern eher nebenbei erledigt und wollte dann nachsehen, ob ich grade auch wirklich die richtige Version teste. Aber leider hat die Abfrage über "version" da nicht für erhellende Info gesorgt (da gibt es keinen Unterschied, jedenfalls ist die Revisions-Nummerierung im svn identisch), sonst hätte ich das jetzt im Dauertest weiter laufen lassen; so gab's halt gleich noch ein update von remote (da war aber CUL_HM nicht bei)...)

@Otto: Netter Code, da setze ich mir doch gleich ein Lesezeichen drauf

.

helmut · 25 Februar 2019, 13:54:44

Zitat von: martinp876 am 24 Februar 2019, 10:35:29
Anbei der Fix (eine Kleinigkeit - mit Wirkung

Laeuft bei mir seit ungefaehr vier Stunden ohne jedes Problem.
Gruss Helmut

Update: Meine HM-TC-IT-WM-W-EU machen doch Probleme.

Code Auswählen

"rp2 fhem45"> l if_wohnzimmer
Internals:
   .lastTimeActivity 1551100800.73665
   .lastTimeCommandAccepted 1551100438.07684
   .lastTimeD-firmware 1551100800.73665
   .lastTimeD-serialNr 1551100800.73665
   .lastTimePairedTo 1551100438.63701
   .lastTimeR-pairCentral 1551100800.73665
   .lastTimeRegL_00. 1551100438.62609
   .lastTimebattery 1551104522.57714
   .lastTimebatteryLevel 1551104522.57714
   .lastTimedesired-temp 1551104522.57714
   .lastTimemeasured-temp 1551104522.57714
   .lastTimestate 1551100801.43511
   .triggerUsed 1
   CFGFN      config/innenfuehler.cfg
   CUL1_MSGCNT 350
   CUL1_RAWMSG A0CCC84703208D700000000CA27::-70.5:CUL1
   CUL1_RSSI  -70.5
   CUL1_TIME  2019-02-25 15:22:12
   CUL2_MSGCNT 350
   CUL2_RAWMSG 05000030CC84703208D700000000CA27
   CUL2_RSSI  -48
   CUL2_TIME  2019-02-25 15:22:12
   DEF        3208D7
   FUUID      5c73ac6f-f33f-053c-128e-861b8b63f7f7939b
   IODev      CUL2
   LASTInputDev CUL2
   MSGCNT     700
   NAME       if_wohnzimmer
   NOTIFYDEV  global
   NR         447
   NTFY_ORDER 50-if_wohnzimmer
   STATE      CMDs_done
   TYPE       CUL_HM
   channel_01 if_wohnzimmer_Weather
   channel_02 if_wohnzimmer_Climate
   channel_03 if_wohnzimmer_WindowRec
   channel_06 if_wohnzimmer_remote
   channel_07 if_wohnzimmer_SwitchTr
   lastMsg    No:CC - t:70 s:3208D7 d:000000 00CA27
   protLastRcv 2019-02-25 15:22:12
   protRcv    351 last_at:2019-02-25 15:22:12
   protSnd    65 last_at:2019-02-25 14:24:06
   protSndB   1 last_at:2019-02-25 14:13:57
   protState  CMDs_done
   rssi_at_CUL1 cnt:350 min:-90 max:-62.5 avg:-70.3 lst:-70.5 
   rssi_at_CUL2 cnt:350 min:-76 max:-46 avg:-50.27 lst:-48 
   .attraggr:
   .attreocr:
     .*
   .attrminint:
     .*:3600
   Helper:
     DBLOG:
       battery:
         bath45DbLog:
           TIME       1551104522.60408
           VALUE      ok
       batteryLevel:
         bath45DbLog:
           TIME       1551104522.60408
           VALUE      2.7
   READINGS:
     2019-02-25 14:20:00   .D-devInfo      03FFFF
     2019-02-25 14:20:00   .D-stc          58
     2018-09-21 13:58:13   .R-btnLock      off
     2018-09-21 13:58:13   .R-globalBtnLock off
     2018-09-21 13:58:13   .R-localResDis  off
     2018-09-21 13:58:13   .R-lowBatLimitRT 2.2 V
     2018-09-21 13:58:13   .R-modusBtnLock off
     2018-09-21 13:58:13   .peerListRDate  2018-09-21 13:58:13
     2019-02-25 15:22:12   .protLastRcv    2019-02-25 15:22:12
     2018-09-22 13:28:19   1               10.2
     2019-02-25 14:20:05   Activity        alive
     2019-02-25 14:20:01   CommandAccepted yes
     2019-02-25 14:20:00   D-firmware      1.3
     2019-02-25 14:20:00   D-serialNr      LEQ0997391
     2019-02-25 14:13:58   PairedTo        0x720902
     2018-09-21 13:58:13   R-burstRx       on
     2018-09-21 13:58:13   R-cyclicInfoMsg on
     2018-09-21 13:58:13   R-cyclicInfoMsgDis 0
     2019-02-25 14:20:00   R-pairCentral   set_0x720902
     2018-09-21 13:58:14   R-sign          off
     2019-02-25 14:14:50   RegL_07.        
     2019-02-25 09:07:37   absoluteHumidity 6.6
     2019-02-25 15:22:02   battery         ok
     2019-02-25 15:22:02   batteryLevel    2.7
     2019-02-25 09:07:27   boostTime       -
     2019-02-25 09:07:27   commReporting   off
     2019-02-25 09:07:27   controlMode     auto
     2019-02-25 15:22:02   desired-temp    17.0
     2019-02-25 09:07:37   dewpoint        5.3
     2019-02-25 09:50:35   humidity        38
     2019-02-25 15:22:02   measured-temp   20.2
     2019-02-25 14:24:06   state           CMDs_done
     2019-02-25 09:50:35   temperature     20.1
     2019-02-25 09:07:27   winOpenReporting off
   helper:
     HM_CMDNR   204
     PONtest    1
     cSnd       017209023208D7000802010A720B090C02,017209023208D70006
     mId        00AD
     peerFriend 
     peerOpt    -:thermostat
     regLst     0
     rxType     6
     supp_Pair_Rep 0
     ack:
     expert:
       def        1
       det        0
       raw        1
       tpl        0
     io:
       lRcTm      29968952
       lstRecType 70
       newChn     +3208D7,00,00,00
       nextSend   1551104532.68404
       nxtSndMcnt CC
       prefIO     
       rxt        0
       tgtDly     120
       vccu       VCCU
       p:
         3208D7
         00
         00
         00
     mRssi:
       mNo        CC
       io:
         CUL1:
           -70.5
           -70.5
         CUL2:
           -40
           -40
     prt:
       awake      0
       bErr       0
       sProc      0
       rspWait:
     q:
       qReqConf   
       qReqStat   
     regCollect:
     role:
       dev        1
     rssi:
       at_CUL1:
         avg        -70.3042857142857
         cnt        350
         lst        -70.5
         max        -62.5
         min        -90
       at_CUL2:
         avg        -50.2714285714286
         cnt        350
         lst        -48
         max        -46
         min        -76
     shRegW:
       07         02
     shadowReg:
     tmpl:
Attributes:
   .mId       00AD
   DbLogInclude temperature,humidity,dewpoint,absoluteHumidity,battery.*
   IODev      CUL1
   IOgrp      VCCU:CUL1
   actCycle   012:00
   actStatus  alive
   autoReadReg 0_off
   event-min-interval .*:3600
   event-on-change-reading .*
   expert     2_full
   firmware   1.3
   group      Thermometer
   model      HM-TC-IT-WM-W-EU
   msgRepeat  1
   room       Erdgeschoss->Wohnzimmer->Devices
   serialNr   LEQ0997391
   subType    thermostat
   verbose    5
   webCmd     getConfig:clear msgEvents

Code Auswählen

"rp2 fhem45"> inf timer if_wohnzimmer.*
"rp2 fhem45"> 2019-02-25 15:26:16.325 CUL_HM if_wohnzimmer_Climate desired-temp: 17.0
2019-02-25 15:26:16.325 CUL_HM if_wohnzimmer_Climate humidity: 39
2019-02-25 15:26:16.325 CUL_HM if_wohnzimmer_Climate measured-temp: 20.2
2019-02-25 15:26:16.325 CUL_HM if_wohnzimmer_Climate T: 20.2 desired: 17.0
2019-02-25 15:26:36.108 CUL_HM if_wohnzimmer_Weather humidity: 39
2019-02-25 15:26:36.108 CUL_HM if_wohnzimmer_Weather T: 20.2 H: 39
2019-02-25 15:26:36.108 CUL_HM if_wohnzimmer_Weather temperature: 20.2
2019-02-25 15:26:36.108 CUL_HM if_wohnzimmer_Weather absoluteHumidity: 6.8
2019-02-25 15:26:36.108 CUL_HM if_wohnzimmer_Weather dewpoint: 5.8

Code Auswählen

$ tail -f /opt/fhem/log/fhem-2019-02.log|grep if_wohnzimmer
2019.02.25 15:26:16.332 4: CUL_HM if_wohnzimmer dupe: dont process
2019.02.25 15:26:36.118 4: CUL_HM if_wohnzimmer dupe: dont process

Bei den anderen sieht das gleich aus.

Ein HM-CC-TC zeigt mit verbose 5 auch die Duplicates im Log an, aber die Werte wie
Temperatur, Feuchte usw. werden in den Readings aktualisiert.

Gruss Helmut

2. Update: Die Duplicates kommen von meinem zweiten CUL.
Darauf haette ich eben schon kommen koennen.

Aber jetzt bin ich mit dem 10_CUL_HM.pm zurueckgegangen und erwartungsgemaess
funktioniert wieder alles. In der telnet-Konsole sehe ich nun die Meldungen vom
Device, nicht dessen Kanaelen:

Code Auswählen

"rp2 fhem45"> inf timer if_wohnzimmer.*
"rp2 fhem45"> 2019-02-25 17:20:42.929 CUL_HM if_wohnzimmer measured-temp: 19.7
2019-02-25 17:20:42.929 CUL_HM if_wohnzimmer T: 19.7 desired: 21.0
2019-02-25 17:21:02.953 CUL_HM if_wohnzimmer T: 19.7 H: 41
2019-02-25 17:21:02.953 CUL_HM if_wohnzimmer temperature: 19.7
2019-02-25 17:21:02.953 CUL_HM if_wohnzimmer absoluteHumidity: 6.9
2019-02-25 17:21:02.953 CUL_HM if_wohnzimmer dewpoint: 6.1

Auch bei den Internals tauchen die Kanaele im Listing nicht mehr auf:

Code Auswählen

"rp2 fhem45"> l if_wohnzimmer
Internals:
   .lastTimeActivity 1551107577.40094
   .lastTimePairedTo 1551111980.85102
   .lastTimeR-pairCentral 1551111980.85175
   .lastTimeRegL_00. 1551111980.83996
   .lastTimeRegL_01. 1551111981.52495
   .lastTimeabsoluteHumidity 1551111662.92217
   .lastTimebattery 1551108903.63088
   .lastTimebatteryLevel 1551108903.63088
   .lastTimeboostTime 1551108903.63088
   .lastTimecommReporting 1551108903.63088
   .lastTimecontrolMode 1551108903.63088
   .lastTimedesired-temp 1551110443.1568
   .lastTimedewpoint 1551111662.92217
   .lastTimehumidity 1551111807.91411
   .lastTimemeasured-temp 1551111642.91
   .lastTimestate 1551111979.78231
   .lastTimetemperature 1551111662.91157
   .lastTimewinOpenReporting 1551108903.63088
   .triggerUsed 1
   CFGFN      config/innenfuehler.cfg
   CUL1_MSGCNT 66
   CUL1_RAWMSG A0E0180103208D77209020208000000::-70.5:CUL1
   CUL1_RSSI  -70.5
   CUL1_TIME  2019-02-25 17:26:21
   CUL2_MSGCNT 66
   CUL2_RAWMSG 050100300180103208D77209020208000000
   CUL2_RSSI  -48
   CUL2_TIME  2019-02-25 17:26:21
   DEF        3208D7
   FUUID      5c7405ea-f33f-053c-3ed3-c58c7bd6e91f831f
   IODev      CUL2
   LASTInputDev CUL2
   MSGCNT     132
   NAME       if_wohnzimmer
   NOTIFYDEV  global
   NR         447
   NTFY_ORDER 50-if_wohnzimmer
   STATE      T: 19.7 H: 41
   TYPE       CUL_HM
   lastMsg    No:01 - t:10 s:3208D7 d:720902 0208000000
   protLastRcv 2019-02-25 17:26:21
   protRcv    66 last_at:2019-02-25 17:26:21
   protSnd    4 last_at:2019-02-25 17:26:21
   protSndB   1 last_at:2019-02-25 17:26:19
   protState  CMDs_done
   rssi_at_CUL1 cnt:66 min:-72 max:-68 avg:-70.1 lst:-70.5 
   rssi_at_CUL2 cnt:66 min:-48 max:-47 avg:-47.37 lst:-48 
   .attraggr:
   .attreocr:
     .*
   .attrminint:
     .*:3600
   Helper:
     DBLOG:
       absoluteHumidity:
         bath45DbLog:
           TIME       1551111662.93017
           VALUE      6.9
       battery:
         bath45DbLog:
           TIME       1551108903.67609
           VALUE      ok
       batteryLevel:
         bath45DbLog:
           TIME       1551108903.67609
           VALUE      2.7
       dewpoint:
         bath45DbLog:
           TIME       1551111662.93017
           VALUE      6.1
       humidity:
         bath45DbLog:
           TIME       1551111807.92516
           VALUE      41
       temperature:
         bath45DbLog:
           TIME       1551111662.93017
           VALUE      19.7

Gruss Helmut