Seltenes Problem mit HM-ES-PMSw1-Pl

[juppzupp]

Hi all,

ist seit Juni das 2te mal das es passiert, natürlich immer wenn ich nicht zu hause bin.....
Habe am HM-ES-PMSw1-Pl eine Espressomaschine die morgens mit einfachem at gestartet wird, um vorzuheizen.

Code Auswählen Erweitern

define Heizer at *05:40 set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
über 'nen doif wird die maschine abgeschaltet, wenn keine entnahme erfolgt.
funktionierte (über jahre) ganz gut, seit juni aber 2 mal nicht.
der log läuft voll :

Code Auswählen Erweitern

2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
2017.09.28 05:40:00 3: CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on



bis dann ein paar minuten später der hmusb in den overload geht :

Code Auswählen Erweitern

2017.09.28 05:49:47 1: HMLAN_Parse: hmusb new condition Warning-HighLoad
2017.09.28 05:50:56 1: HMLAN_Parse: hmusb new condition ERROR-Overload


als ich dann heute abend davon erfuhr, hatte ich cirka 29000 messages in der queue.

ich bräuchte mal ne anstubser, wie/wo ich nachdem fehler suchen, bzw ihn eingrenzen kann.

danke

Code Auswählen Erweitern

Latest Revision: 14242

File                Rev   Last Change

fhem.pl             14152 2017-05-01 09:07:23Z rudolfkoenig
90_at.pm            13840 2017-03-29 07:52:29Z rudolfkoenig
98_autocreate.pm    11984 2016-08-19 12:47:50Z rudolfkoenig
98_cmdalias.pm      12935 2017-01-02 19:51:46Z rudolfkoenig
10_CUL_HM.pm        14203 2017-05-05 21:59:16Z martinp876
93_DbLog.pm         14030 2017-04-18 20:24:55Z DS_Starter
93_DbRep.pm         14010 2017-04-17 07:38:36Z DS_Starter
98_DOIF.pm          14112 2017-04-26 16:09:48Z Damian
98_dummy.pm         12700 2016-12-02 16:49:42Z rudolfkoenig
98_EDIPLUG.pm       12458 2016-10-28 18:00:25Z wzut
91_eventTypes.pm    11984 2016-08-19 12:47:50Z rudolfkoenig
01_FHEMWEB.pm       14193 2017-05-05 12:49:23Z rudolfkoenig
92_FileLog.pm       14206 2017-05-06 11:42:54Z rudolfkoenig
98_help.pm          13694 2017-03-13 19:24:13Z betateilchen
98_HMinfo.pm        14086 2017-04-23 13:29:04Z martinp876
00_HMLAN.pm         14073 2017-04-22 13:45:25Z martinp876
30_HUEBridge.pm     13710 2017-03-15 12:17:49Z justme1968
31_HUEDevice.pm     13711 2017-03-15 12:30:42Z justme1968
49_IPCAM.pm          2626 2013-02-01 19:19:15Z mfr69bs
73_MPD.pm           13247 2017-01-26 20:20:08Z Wzut
91_notify.pm        13630 2017-03-06 21:05:08Z rudolfkoenig
32_speedtest.pm     12056 2016-08-22 19:30:31Z justme1968
98_structure.pm     14015 2017-04-17 15:05:01Z rudolfkoenig
99_SUNRISE_EL.pm    12485 2016-11-01 15:18:51Z rudolfkoenig
98_SVG.pm           14140 2017-04-30 06:06:11Z rudolfkoenig
98_telnet.pm        13443 2017-02-19 12:51:22Z rudolfkoenig
45_TRX.pm           11456 2016-05-15 20:19:24Z wherzig
46_TRX_ELSE.pm      11451 2016-05-15 19:04:06Z wherzig
46_TRX_WEATHER.pm   11450 2016-05-15 19:03:23Z wherzig
59_Twilight.pm      14039 2017-04-19 19:59:56Z orti-otto
99_Utils.pm         13259 2017-01-28 17:39:39Z rudolfkoenig
77_UWZ.pm           12835 2016-12-19 20:11:33Z CoolTux
98_version.pm       13628 2017-03-06 20:43:50Z markusbloch
98_weblink.pm       13558 2017-03-01 09:42:51Z rudolfkoenig

Blocking.pm         12648 2016-11-24 12:15:25Z rudolfkoenig
Color.pm            11159 2016-03-30 16:08:06Z justme1968
DevIo.pm            13865 2017-04-01 09:10:44Z rudolfkoenig
HMConfig.pm         14150 2017-05-01 07:07:48Z martinp876
No Id found for HMConfig_SenTHPL.pm
HttpUtils.pm        13998 2017-04-15 12:33:23Z rudolfkoenig
RTypes.pm           10476 2016-01-12 21:03:33Z borisneubert
SetExtensions.pm    12935 2017-01-02 19:51:46Z rudolfkoenig
TcpServerUtils.pm   13967 2017-04-11 09:32:30Z rudolfkoenig

fhemweb.js                 14057 2017-04-21 08:30:42Z rudolfkoenig
fhemweb_colorpicker.js     13580 2017-03-02 13:03:29Z justme1968
fhemweb_fbcalllist.js      13629 2017-03-06 20:50:43Z markusbloch
fhemweb_readingsGroup.js   13580 2017-03-02 13:03:29Z justme1968
fhemweb_readingsHistory.js 13580 2017-03-02 13:03:29Z justme1968
fhemweb_sortable.js        13629 2017-03-06 20:50:43Z markusbloch
fhemweb_uzsu.js            13580 2017-03-02 13:03:29Z justme1968

—
Internals:
   DEF        283B50
   IODev      hmusb
   LASTInputDev hmusb
   MSGCNT     27
   NAME       CUL_HM_HM_ES_PMSw1_Pl_283B50
   NOTIFYDEV  global
   NR         66
   NTFY_ORDER 50-CUL_HM_HM_ES_PMSw1_Pl_283B50
   STATE      CMDs_done
   TYPE       CUL_HM
   channel_01 CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw
   channel_02 CUL_HM_HM_ES_PMSw1_Pl_283B50_Pwr
   channel_03 CUL_HM_HM_ES_PMSw1_Pl_283B50_SenPwr
   channel_04 CUL_HM_HM_ES_PMSw1_Pl_283B50_SenI
   channel_05 CUL_HM_HM_ES_PMSw1_Pl_283B50_SenU
   channel_06 CUL_HM_HM_ES_PMSw1_Pl_283B50_SenF
   hmusb_MSGCNT 27
   hmusb_RAWMSG E283B50,0000,B66173D0,FF,FFC3,19845E283B500000008000000000000000093502
   hmusb_RSSI -61
   hmusb_TIME 2017-09-28 22:57:28
   lastMsg    No:19 - t:5E s:283B50 d:000000 8000000000000000093502
   protCmdDel 1
   protLastRcv 2017-09-28 22:57:28
   protResnd  3 last_at:2017-09-28 21:52:18
   protResndFail 1 last_at:2017-09-28 21:52:23
   protSnd    3 last_at:2017-09-28 21:54:36
   protState  CMDs_done
   rssi_at_hmusb min:-64 lst:-61 avg:-61.18 max:-59 cnt:27
   Helper:
     Dblog:
       Activity:
         Logdb:
           TIME       1506628914.80824
           VALUE      alive
       Poweron:
         Logdb:
           TIME       1506628476.49441
           VALUE      2017-09-28 21:54:36
       State:
         Logdb:
           TIME       1506628476.49441
           VALUE      CMDs_done
   Readings:
     2017-09-28 22:01:54   Activity        alive
     2017-07-30 13:34:37   D-firmware      2.5
     2017-07-30 13:34:37   D-serialNr      LEQ0184299
     2017-09-27 17:47:21   PairedTo        0xFECAFE
     2017-07-30 14:12:49   R-pairCentral   0xFECAFE
     2017-09-27 17:47:21   RegL_00.        02:81 0A:FE 0B:CA 0C:FE 15:FF 18:00 00:00
     2017-09-28 21:54:36   powerOn         2017-09-28 21:54:36
     2017-09-28 21:54:36   state           CMDs_done
   Helper:
     HM_CMDNR   25
     PONtest    0
     cSnd       ,01FECAFE283B50010E
     mId        00AC
     rxType     1
     supp_Pair_Rep 0
     Expert:
       def        1
       det        0
       raw        1
       tpl        0
     Io:
       newChn     +283B50,00,01,00
       nextSend   1506632248.33814
       rxt        0
       vccu       vccu
       p:
         283B50
         00
         01
         00
       prefIO:
         hmusb
     Mrssi:
       mNo        19
       Io:
         hmusb      -59
     Prt:
       bErr       0
       sProc      0
       Rspwait:
     Q:
       qReqConf
       qReqStat
     Role:
       dev        1
       prs        1
     Rssi:
       At_hmusb:
         avg        -61.1851851851852
         cnt        27
         lst        -61
         max        -59
         min        -64
     Tmpl:
Attributes:
   IODev      hmusb
   IOgrp      vccu:hmusb
   actCycle   000:10
   actStatus  alive
   alias      Espresso
   autoReadReg 4_reqStatus
   event-on-change-reading .*
   expert     2_full
   firmware   2.5
   model      HM-ES-PMSw1-Pl
   room       CUL_HM
   serialNr   LEQ0184299
   subType    powerMeter
   webCmd     getConfig

[fiedel]

An deinem Schalter ist alles in Ordnung und das at macht auch alles richtig. Die Startzeit ist jedes Mal "5:40:00". Du kannst im Ausführungsteil sowas programmieren wie "wenn der Schalter aus ist -> schalte ein" (per "oldValue"). Dann kann nur ein Mal eingeschalten werden.

[martinp876]

Mir ist unklar, warum der Timer so oft ausgeführt wird. Das sollte nur einmal passieren. Es ist immer der gleiche Tag.  Ich kann nicht erkennen, dass es ein wiederholter aus culhm ist. Der sollte so etwas auch nicht machen.
Das kommt nur manchmal vor?

[juppzupp]

Hi,

ich bin mir halt auch nicht sicher, warum (oder ob) der timer so oft ausgeführt wird, oder ob es eine loop in culhm ist.
ich habe oben im beitrag nur gekürzt dargestellt, der log ist 325 MB groß geworden, das nahm einfach gar kein ende mehr :

Code Auswählen Erweitern

/opt/fhem/log$ more fhem-2017-09.log | grep '2017.09.28' | grep -c 'CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw\ on'
4934581

meine Bessere hälfte hatte irgendwann nachmittags den zwischenstecker aus der steckdose gezogen, ich dann abends gegen 22.00 erst nen clear msgEvents abgesetzt, aber die queue lief direkt wieder voll, und so habe ich ich nen shutdown restart hinterher geschickt, meine bessere hälfte den stecker wieder eingesteckt. seitdem ist ruhe.

es ist seit juni das 2te mal passiert. ich rauf mir die haare weil ich gar nicht weiss wo ich ansetzen soll.

danke !

[martinp876]

Der Ausschnitt war nicht komplett? Der erste Teil komplett ist interessant

[juppzupp]

Es sind 4934581 Zeilen mit der Nachricht

Code Auswählen Erweitern

CUL_HM set CUL_HM_HM_ES_PMSw1_Pl_283B50_Sw on
Natürlich mit fortlaufenden Zeitstempel

[martinp876]

Ich will nicht wissen, wie oft es drin ist. Ich brauche nicht das ganze File. Ich will einen Log mit allen Einträgen zu Beginn des Problems. Was ist da im Umfeld passiert.
Dein grep filtert nur auf das eine Event. Wann es anfängt ist ebenso unklar.... Und was sonst so passiert.

[juppzupp]

Hier im Anhang.
zip = fhem.log vom ganzen Tag,
csv = devices-dblog von 05:39-05:59

Danke!