keine Reaktion auf Kommandos über HMLAN

Begonnen von geek, 19 Januar 2014, 21:35:22

Vorheriges Thema - Nächstes Thema
Drucken
Nach unten Seiten1
Benutzer-Aktionen

geek

19 Januar 2014, 21:35:22
Hi,

hatte in den letzten Tagen mehrfach das Problem, daß die Kommunikation zwischen fhem und HMLAN "hängen" geblieben ist: Wenn ich dann logging eingeschaltet habe, habe ich über den betroffenen HMLAN noch traffic kommen sehen und fhem hat auch brav keepalives geschickt - aber nicht die kommandos, die ich abgesetzt habe. Im "Inform timer" tauchen die dann nach ner Weile als "IOErr" auf.

Das tritt sporadisch auf - bisher nach/bei Änderungen oder wenn ich diverse Fensterkontakte mehrfach in Folge auslöse. Wenn ich  Log und hminfo msgStats richtig lese bin ich  von Overloads noch meilenweit entfernt. Habe das inzwischen mit beiden HMLANs gesehen. Nach Power-Cycle des betroffenen HMLANs läuft wieder alles.

Heute hatte ich das log schon laufen... habe also hoffentlich was greifbares. Habe auch msgStats + protoEvents - nur hat hat meine tty leider den output abgeschnitten - hoffe aber, das hilft trotzdem.

Bei folgendem output hing der HMUG nachdem ich neue aktoren angelernt/konfiguriert habe.

Code Auswählen
HMUG: 83D2E1
define ug_kr_tast_rollo CUL_HM 2058A2
define ug_kr_rollo_rechts CUL_HM 221A12
define ug_kr_rollo_links CUL_HM 220CDD


Gegen 18:38:13 habe ich dem HMUG den power-cycle gegeben. Angehängt ist ein logfile ab 18:20.
Die missing-Acks vom ug_kr_rollo_rechts kommen vom anfänglich fehlenden pairing.

Code Auswählen
fhem> set hm msgStat
msg statistics

                 |------------------------------------------------------------------------>*
  receive hour  :| 00| 01| 02| 03| 04| 05| 06| 07| 08| 09| 10| 11| 12| 13| 14| 15| 16| 17| 18| 19| 20| 21| 223
      StatCntRfresh:|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|0
      HMEG      :|259|262|257|255|259|261|258|309|275|270|260|259|262|270|257|275|519|731|390|259|257|464|2678
      StatCntRfrh:|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0
      HMUG      :|243|249|247|253|254|256|250|346|289|268|252|259|267|278|257|286|445|589|360|255|256|605|2580
  send    hour  :| 00| 01| 02| 03| 04| 05| 06| 07| 08| 09| 10| 11| 12| 13| 14| 15| 16| 17| 18| 19| 20| 21| 223
      StatCntRfresh:|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|0
      HMEG      :|  0|  6|  0|  0|  2|  8|  0| 31| 19| 11|  0|  0|  5|  9|  0| 10| 19|  6| 14|  0|  2|183|  84
      StatCntRfrh:|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0
      HMUG      :|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  0|  1|128|220|108|  1|  0|  0|  00
                 |------------------------------------------------------------------------>*
  receive day   :| Mon| Tue| Wed| Thu| Fri| Sat| Sun|# tdy
      StatCntRfresh:|   0|   0|   0|   0|   0|   0|   0|#   0
      HMEG      :|   0|   0|   0|   0|   0|   0|1726|#7403
      StatCntRfrh:|   0|   0|   0|   0|   0|   0|   0|#   0
      HMUG      :|   0|   0|   0|   0|   0|   0|1853|#7282
  send    day   :| Mon| Tue| Wed| Thu| Fri| Sat| Sun|# tdy
      StatCntRfresh:|   0|   0|   0|   0|   0|   0|   0|#   0
      HMEG      :|   0|   0|   0|   0|   0|   0| 214|# 347
      StatCntRfrh:|   0|   0|   0|   0|   0|   0|   0|#   0
      HMUG      :|   0|   0|   0|   0|   0|   0|   1|# 458

fhem> set hm protoEvents
protoEvents done:
    name                :State           |CmdPend           |Snd               |LastRcv       |Resnd
    a_giebel_temp       :  -             | -                | -                |01-19 18:34:46| -
    eg_bd_boiler        : done           | -                |47:01-19 07:00:01 |01-19 10:27:37| -
    eg_bd_fenster       : done           | -                |12:01-19 15:43:20 |01-19 15:43:20| -
    eg_bd_heiz          : done           | -                |22:01-19 07:19:14 |01-19 18:34:39| -
    eg_bd_temp          :  -             | -                | -                |01-19 18:35:59| -
    eg_f_display        : done           | -                |207:01-19 15:56:06|01-19 15:56:06|1:01-17 17:19:
    eg_f_lampe_decke    : done           | -                |244:01-19 16:56:26|01-19 16:56:26| -
    eg_f_tast_homestatus:  -             | -                | -                |01-19 15:09:19| -
    eg_f_tast_wz        : pending        |9 pending         | -                |01-17 18:04:09| -
    eg_of_heiz          : done           | -                |4:01-19 04:37:18  |01-19 18:36:05| -
    eg_of_it_monitor    : done           | -                |10:01-19 13:40:17 |01-19 15:09:42| -
    eg_sz_fenster       : done           | -                |15:01-19 07:53:19 |01-19 07:53:19| -
    eg_sz_heiz          : done           | -                |24:01-19 08:32:56 |01-19 18:34:25| -
    eg_sz_lampe_decke   : done           | -                |175:01-19 07:39:52|01-19 07:39:52| -
    eg_sz_tast_bett     :  -             | -                | -                |01-19 07:35:15| -
    eg_sz_temp          :  -             | -                | -                |01-19 18:35:23| -
    eg_wz_fenster_terassentuer: done           | -                |77:01-19 13:28:49 |01-19 13:28:49| -
    eg_wz_heiz_kueche   : done           | -                |53:01-19 05:47:04 |01-19 18:34:39| -
    eg_wz_heiz_terasse  : done           | -                |52:01-19 05:45:58 |01-19 18:35:36| -
    eg_wz_lampe_tuer    : done           | -                |39:01-19 16:11:15 |01-19 16:11:15| -
    eg_wz_media_tv      : done           | -                |9:01-19 13:40:18  |01-19 15:13:19| -
    eg_wz_temp          :  -             | -                | -                |01-19 18:34:57| -
    ug_bd_temp          :  -             | -                | -                |01-19 18:35:09| -
    ug_kr_fenster_tuer  : done           | -                |85:01-19 17:05:31 |01-19 17:05:31| -
    ug_kr_heiz          : done           | -                |93:01-19 16:58:12 |01-19 18:35:12| -
    ug_kr_pflanzlampe   : done           | -                |7:01-19 15:48:42  |01-19 15:48:42| -
    ug_kr_rollo_links   : pending        |1 pending         |42:01-19 18:26:29 |01-19 18:31:30| -
    ug_kr_rollo_rechts  : done_Errors:1  | -                |42:01-19 18:31:12 |01-19 18:32:20|10:01-19 18:31
    ug_kr_rollo_tuer    : done_Errors:1  | -                |132:01-19 17:58:18|01-19 18:31:26|7:01-19 17:58:
    ug_kr_tast_rollo    : done_Errors:1  | -                |61:01-19 18:26:53 |01-19 18:31:21|1:01-19 17:52:
    ug_kr_temp          : done           | -                |4:01-19 16:58:46  |01-19 18:35:49| -
==============================================================================================================
    sum                 3                |10                |1456              |31            |19

    CUL_HM queue:0

    autoReadReg pending: recent:ug_kr_rollo_rechts
    status request pending:
    autoReadReg wakeup pending:
    status request wakeup pending:

    IODevs:HMEG:opened pending=0 condition:ok
            msgLoadEst: 1hour:2% 10min steps: 0/2/0/0/0/0
           HMUG:opened pending=1 condition:ok
            msgLoadEst: 1hour:12% 10min steps: 2/5/0/0/3/0

martinp876

#1
20 Januar 2014, 11:15:02
Hallo geek,

einen Overload solltest du im list oder status des HMLAN sehen. Die Zähler von FHEM können hinterher hinken wenn es einen neustart von FHEM gegeben hat, aber keinen des HMLAN. Den Level kann ich nicht aus dem HMLAN auslesen.

kannst du einmal ein list HMUG und HMEG schicken?

dein ug_kr_rollo_rechts soll über welches IO device senden? Hast du IODev gesetzt?
Gruss Martin

geek

#2
20 Januar 2014, 11:52:02
Hi Martin,

wie gesagt - einen overload habe ich nicht gesehen (was nicht unbedingt was bedeuten muss ;) ). Fhem hatte in den Stunden vorher auch keinen restart.

Keine Kommandos von FHEM zum HMLAN würde ich ja erwarten wenn FHEM glaubt einen overload zu haben - aber dann müßten die doch später geschickt werden und nicht als IOErr weggeworfen werden, oder?

Die Kommandos werden von FHEM ja garnicht erst an den HMLAN geschickt. Hatte mal nen tcpdump laufen der zu den fhem logs passt: Auch da war nur der Watchdog und reinkommender Funktraffic von HMLAN -> fhem zu sehen.

Die ug_.* Geräte habe ich alle mit dem HMUG gepaired und den auch als IODev gesetzt.

Vermute, ein List der HMLANs bring erst was, wenn das Problem wieder auftritt - hier aber schonmal der aktuelle status:

Code Auswählen
list HMUG
Internals:
   DEF        192.168.2.21:1000
   DeviceName 192.168.2.21:1000
   FD         11
   HMUG_MSGCNT 26133
   HMUG_TIME  2014-01-20 11:32:07
   HM_CMDNR   162
   NAME       HMUG
   NR         36
   NTFY_ORDER 50-HMUG
   PARTIAL
   RAWMSG     E221330,0000,03A088EA,FF,FFC7,1786102213300000000A88B90F0040
   RSSI       -57
   STATE      opened
   TYPE       HMLAN
   XmitOpen   1
   assignedIDs 2217DC,238D0D,22A60A,2437B0,22A992,220CDD,221F1C,1AA711,22A98F,22A999,22A9AC,24D171,1B5131,24C9
   assignedIDsCnt 22
   assignedIDsReport 6
   firmware   0.961
   msgKeepAlive dlyMax:3.197 bufferMin:1
   msgLoadEst 1hour:0% 10min steps: 0/0/0/0/0/0
   msgParseDly min:-21 max:2563 last:35 cnt:26030
   owner      83D2E1
   serialNr   KEQ0852689
   uptime     000 16:54:12.458
   Readings:
     2014-01-19 18:38:13   Xmit-Events     ok:1
     2014-01-19 18:38:13   cond            ok
     2014-01-19 18:38:13   prot_disconnected last
     2014-01-19 18:38:13   prot_init       last
     2014-01-19 18:38:13   prot_ok         last
   Helper:
     000001:
       flg        0
       msg
       to         1390153095.19791
     1f4c1f:
       chn        01
       flg        0
       msg
       name       ug_kr_temp
       newChn     +1F4C1F,00,01,
       to         1390147128.04956
     2058a2:
       chn        02
       flg        0
       msg
       name       CUL_HM_HM_PB_2_WM55_2058A2
       newChn     +2058A2,00,01,
       to         1390152414.98912
     20595b:
       chn        01
       flg        0
       name       eg_f_tast_homestatus
       newChn     +20595B,00,01,
     220cdd:
       chn        02
       flg        0
       msg
       name       ug_kr_rollo_links
       newChn     +220CDD,00,01,
       to         1390200467.04997
     220cfd:
       chn        02
       flg        0
       msg
       name       ug_kr_rollo_tuer
       newChn     +220CFD,00,01,
       to         1390200467.4905
     221a12:
       chn        02
       flg        0
       msg
       name       ug_kr_rollo_rechts
       newChn     +221A12,00,01,
       to         1390200467.2893
     221f1c:
       chn        86
       flg        0
       msg
       name       ug_kr_heiz
       newChn     +221F1C,00,01,
       to         1390205978.81315
     22a992:
       chn        02
       flg        0
       msg
       name       ug_kr_pflanzlampe
       newChn     +22A992,00,01,
       to         1390154462.04417
     238d0d:
       chn        01
       flg        0
       msg
       name       ug_kr_fenster_tuer
       newChn     +238D0D,01,01,FE1F
       to         1390155742.29732
     245b68:
       chn        01
       flg        0
       name       eg_sz_tast_bett
       newChn     +245B68,00,01,
     83d2e1:
       flg        0
     Dly:
       cnt        26030
       lst        35
       max        2563
       min        -21
     K:
       BufMin     1
       DlyMax     3.197
       Next       1390213948.05072
       Start      1390213923.05072
     Log:
       all        1
       sys        1
       ids:
         all
         sys
     Q:
       HMcndN     0
       answerPend 0
       hmLanQlen  1
       keepAliveRec 1
       keepAliveRpt 0
       apIDs:
       Cap:
         0          0
         1          0
         2          0
         3          0
         4          0
         5          0
         last       3
         sum        0
     Ref:
       drft       -0.00015999360025599
       hmtL       60848484
       kTs        0
       offL       1390153074569
       sysL       1390213923053
Attributes:
   hmId       83D2E1
   hmLanQlen  1_min
   logIDs     sys,all
   room       Unsorted
   structexclude .*:.*

fhem> list HMEG
Internals:
   DEF        192.168.2.19:1000
   DeviceName 192.168.2.19:1000
   FD         10
   HMEG_MSGCNT 25805
   HMEG_TIME  2014-01-20 11:32:07
   HM_CMDNR   190
   NAME       HMEG
   NR         34
   NTFY_ORDER 50-HMEG
   PARTIAL
   RAWMSG     E221330,0000,0E230CA4,FF,FFD5,1786102213300000000A88B90F0040
   RSSI       -43
   STATE      opened
   TYPE       HMLAN
   XmitOpen   1
   assignedIDs 2217DC,238D0D,22A60A,2437B0,22A992,220CDD,221F1C,1AA711,20595B,22A98F,22A999,22A9AC,24D171,1B59
   assignedIDsCnt 23
   assignedIDsReport 19
   firmware   0.961
   msgKeepAlive dlyMax:3.242 bufferMin:1
   msgLoadEst 1hour:0% 10min steps: 0/0/0/0/0/0
   msgParseDly min:-19 max:2574 last:5 cnt:25726
   owner      83D2E0
   serialNr   KEQ0852556
   uptime     002 65:52:58.020
   Readings:
     2014-01-17 17:40:52   Xmit-Events     ok:1
     2014-01-17 17:40:52   cond            ok
     2014-01-17 17:39:48   prot_disconnected last
     2014-01-17 17:40:52   prot_init       last
     2013-12-31 14:07:18   prot_keepAlive  last
     2014-01-17 17:40:52   prot_ok         last
     2014-01-17 17:39:48   prot_timeout    last
   Helper:
     000001:
       flg        0
       msg
       to         1389976854.0899
     1aa711:
       chn        02
       flg        0
       msg
       name       eg_sz_lampe_decke
       newChn     +1AA711,00,01,
       to         1390198502.02148
     1b5131:
       chn        03
       flg        0
       msg
       name       eg_f_lampe_decke
       newChn     +1B5131,00,01,
       to         1390207277.67921
     1d4547:
       chn        80
       flg        0
       msg
       name       eg_f_display
       newChn     +1D4547,00,01,
       to         1390203874.74673
     20595b:
       chn        01
       flg        0
       name       eg_f_tast_homestatus
       newChn     +20595B,00,01,
     220cfd:
       chn        00
       flg        0
       msg
       name       CUL_HM_HM_LC_BL1_FM_220CFD
       newChn     +220CFD,00,01,
       to         1390148806.20899
     22123d:
       chn        86
       flg        0
       msg
       name       eg_bd_heiz
       newChn     +22123D,00,01,
       to         1390202618.1279
     221330:
       chn        86
       flg        0
       msg
       name       eg_sz_heiz
       newChn     +221330,00,01,
       to         1390202671.12323
     2217dc:
       chn        02
       flg        0
       msg
       name       eg_of_heiz
       newChn     +2217DC,00,01,
       to         1390184561.10559
     221a12:
       chn        01
       flg        0
       msg
       name       CUL_HM_HM_LC_BL1_FM_221A12
       newChn     +221A12,00,01,
       to         1390152460.20473
     221f48:
       chn        86
       flg        0
       msg
       name       eg_wz_heiz_terasse
       newChn     +221F48,00,01,
       to         1390202644.71879
     2221d9:
       chn        86
       flg        0
       msg
       name       eg_wz_heiz_kueche
       newChn     +2221D9,00,01,
       to         1390202656.47527
     22a60a:
       chn        02
       flg        0
       msg
       name       eg_bd_boiler
       newChn     +22A60A,00,01,
       to         1390197602.01302
     22a98f:
       chn        02
       flg        0
       msg
       name       eg_wz_lampe_tuer
       newChn     +22A98F,00,01,
       to         1390202565.94912
     22a999:
       chn        02
       flg        0
       msg
       name       eg_wz_media_tv
       newChn     +22A999,00,01,
       to         1390168858.11727
     22a9ac:
       chn        02
       flg        0
       msg
       name       eg_of_it_monitor
       newChn     +22A9AC,00,01,
       to         1390168856.61784
     2437b0:
       chn        01
       flg        0
       msg
       name       eg_wz_fenster_terassentuer
       newChn     +2437B0,01,01,FE1F
       to         1390157164.62108
     245b68:
       chn        01
       flg        0
       name       eg_sz_tast_bett
       newChn     +245B68,00,01,
     24cc85:
       chn        01
       flg        0
       msg
       name       eg_sz_fenster
       newChn     +24CC85,00,01,
       to         1390201151.46088
     24d171:
       chn        01
       flg        0
       msg
       name       eg_bd_fenster
       newChn     +24D171,00,01,
       to         1390201169.92724
     83d2e0:
       flg        0
     Dly:
       cnt        25726
       lst        5
       max        2574
       min        -19
     K:
       BufMin     1
       DlyMax     3.242
       Next       1390213948.01391
       Start      1390213923.01391
     Log:
       all        1
       sys        1
       ids:
         all
         sys
     Q:
       HMcndN     0
       answerPend 0
       hmLanQlen  1
       keepAliveRec 1
       keepAliveRpt 0
       apIDs:
       Cap:
         0          0
         1          0
         2          0
         3          0
         4          0
         5          0
         last       3
         sum        0
     Ref:
       drft       -0.000159987201023918
       hmtL       237174009
       kTs        0
       offL       1389976749008
       sysL       1390213923017
Attributes:
   hmId       83D2E0
   hmLanQlen  1_min
   logIDs     sys,all
   room       Unsorted
   structexclude .*:.*
   wdTimer    25



Danke,
Rainer

martinp876

#3
20 Januar 2014, 12:12:39
Hallo Rainer,

auch wenn das IO device nicht sendebereit ist - es wird eine Zeit gewartet... gibt es einentimeout und einen IO error.

du pairst - dann sollte auch das IODev in den Attributen festgelegt werden ( du solltest dann speichern).

schlecht ist
18:30:14.669 0: HMLAN_Send:  HMUG S:

da sollte
HMLAN_Send:  HMUG S:+221A12,00,01,
stehen
und das müsste aus
Internals:
   NAME       HMUG
   221a12:
       newChn     +221A12,00,01,

abgeleitet werden. warum dies 'leer' ist kann ich nicht erkennen. Im List ist alles korrekt

Gruss Martin

geek

#4
20 Januar 2014, 13:18:30
Hi Martin,

wenn ich das richtig lese fangen die leeren Sends ein paar Sekunden nach dem (endlich) erfolgreichen pairen an:

2014.01.19 18:29:55.562 3: CUL_HM pair: ug_kr_rollo_rechts blindActuator, model HM-LC-BL1-FM ...
2014.01.19 18:29:55.565 2: CUL_HM set ug_kr_rollo_rechts getConfig
...
2014.01.19 18:29:57.359 0: HMLAN_Send:  HMUG S:

Ich bin mir nicht sicher, ob zu dem Zeitpunkt nicht noch irgend welcher Mist von meinen dummheitsverursachten Fehlversuchen in der queue war.

Und ja, IODev ist als attribut vorhanden. Das habe ich schon schmerzhaft gelernt, bevor du das beim Pairen automatisch gesetzt hast :D

Gibt es was, das ich beim "nächsten mal" sammeln soll? Bisher sind auf meiner Liste:
- raw log
- list HMUG
- list HMUG
- list <betroffenes device>
- set hm msgStats
- set hm protoEvents
- wenn möglich inform-timer output und timestamps wann welches fhem kommando abgesetzt wurde.

Leider weiß ich noch nicht, wie ich das gezielt reproduzieren kann. Bisher ist das nur sporadisch - von daher auch nicht soooooooooo schlimm ;) 

Rainer

martinp876

#5
20 Januar 2014, 14:29:33
ZitatUnd ja, IODev ist als attribut vorhanden. Das habe ich schon schmerzhaft gelernt, bevor du das beim Pairen automatisch gesetzt hast

hm...
als "internal" wird es immer gesetzt (zumindest versucht). Als Attribut kann man das Internal beeinflussen.
Beim Pairen wird nun das Attribut gesetzt - und hoffentlich auch das "internal".
Zum Senden wird das 'internal' verwendet!.

ZitatIch bin mir nicht sicher, ob zu dem Zeitpunkt nicht noch irgend welcher Mist von meinen dummheitsverursachten Fehlversuchen in der queue war.
und ich hoffe, dass beim pairen alles so gesetzt wird, wie ich es mir vorstellen :)

Ich denke, du hast eine komplette liste der Logs.
Beachte, dass das List vom Device sein sollte, nicht von Channel.

Gruss Martin
Drucken
Nach oben Seiten1
Benutzer-Aktionen