nach Shutdown Restart häufig Fehler "no IO device identified" bei HM-Devices

cs-online · 01 Mai 2019, 20:15:04

Hallo,

ich habe als IO-Device für meine HMs das HM-MOD-UART über ESP-Link angebunden. Hier ein List vom Device:

Internals:
   AssignedPeerCnt 10
   CNT        167
   Clients    :CUL_HM:
   DEF        uart://IP:23
   DEVCNT     167
   DevState   99
   DevType    UART
   DeviceName IP:23
   FD         141
   FUUID      5c477543-f33f-1755-32d2-0919da8b20955b98
   LastOpen   1556733461.60073
   NAME       HM_Gateway
   NOTIFYDEV  global
   NR         576
   NTFY_ORDER 50-HM_Gateway
   PARTIAL    
   RAWMSG     040200
   RSSI       -39
   STATE      opened
   TYPE       HMUARTLGW
   XmitOpen   1
   model      HM-MOD-UART
   msgLoadCurrent 0
   msgLoadHistory 0/0/-/-/-/-/-/-/-/-/-/-
   msgLoadHistoryAbs 0/0/0/-/-/-/-/-/-/-/-/-/-
   owner      424242
   Helper:
     CreditTimer 53
     FW         66561
     Initialized 1
     SendCnt    29
     AckPending:
     LastSendLen:
       3
       3
     Log:
       IDs:
     PendingCMD:
     RoundTrip:
       Delay      0.00578689575195312
     loadLvl:
       lastHistory 1556734077.20771
   MatchList:
     1:CUL_HM   ^A......................
   Peers:
     3370B5     +3370B5,00,00,00
     3370DE     +3370DE,00,00,00
     33738F     +33738F,00,00,00
     337676     +337676,00,00,00
     33767A     +33767A,00,00,00
     3376DA     +3376DA,00,00,00
     3376EE     +3376EE,00,00,00
     38ADD0     +38ADD0,00,00,00
     38AE5F     +38AE5F,00,00,00
     38BA82     +38BA82,00,00,00
   READINGS:
     2019-05-01 19:57:51   D-HMIdAssigned  424242
     2019-05-01 19:57:51   D-HMIdOriginal  58341D
     2019-05-01 19:57:52   D-firmware      1.4.1
     2019-05-01 19:57:54   D-serialNr      OEQ0304477
     2019-05-01 19:57:15   D-type          HM-MOD-UART
     2019-05-01 19:57:58   cond            ok
     2019-05-01 19:57:58   load            0
     2019-05-01 19:57:58   loadLvl         low
     2019-05-01 19:57:41   state           opened
   helper:
Attributes:
   dutyCycle  0
   group      Funk_Gateways
   hmId       424242
   icon       cul_868
   room       Schnittstellen
   verbose    1

Läuft super, aber ganz häufig bekomme ich nach einem Shutdown Restart den Fehler "no IO device identified" beim anwählen eines HM-Devices. nach erneutem Neustart geht's dann meist wieder.

Kann man da was gegen unternehmen und woran liegt das wohl ?

Grüße

Christian

Pati_Alpha · 14 Mai 2019, 21:08:53

Hey, das Problem habe ich auch!

Gibts hier schon einen Lösungsansatz? Oder irgendwelche News von den Modulschreiberlingen?

Was bei mir als Workaround immer hilft: Die entsprechenden Schalter manuell aus/an machen.
Passiert aber lustigerweise nur bei zwei Unterputz-Lichtschaltern (alle die ich habe). Bei Heizungsthermostaten, Hutschinenaktoren, Türsensoren etc nicht.

Beta-User · 15 Mai 2019, 08:04:02

Ihr habt nicht zufällig eine VCCU eingerichtet

?

Das ist bei CUL_HM grundsätzlich sehr zu empfehlen.

cs-online · 15 Mai 2019, 08:17:29

Hallo,

nein, habe keine VCCU. Wenn ich dann wieder mit Shutdown Restart neu starte, geht's in aller Regel wieder... Nervt aber trotzdem...

Grüße

Christian

Beta-User · 15 Mai 2019, 09:19:09

Dann richte doch eine VCCU ein

.

Kostet nichts außer etwas Zeit, und hilft, manche Probleme zu vermeiden...

Ma_Bo · 16 Mai 2019, 03:14:23

Der Fehler kann evtl. daher kommen, dass die Reihenfolge in der Config nicht stimmt.

Erst sollte das IO kommen und dann die HM Geräte.

Zitat aus dem Wiki: (https://wiki.fhem.de/wiki/Virtueller_Controller_VCCU)

ZitatBeim Start von FHEM wird die cfg Zeilenweise abgearbeitet und für jedes HM Gerät geprüft ob ein IO vorhanden ist, gegebenenfalls erfolgt ein Fehlereintrag im Log (unknown IODev specified). Wenn der neue IO erst am Ende der cfg definiert ist, ist er für alle davor liegenden HM Geräte nicht vorhanden. Das ist nur ein Schönheitsfehler beim Start von FHEM, im laufenden Betrieb spielt das keine Rolle.

Grüße Marcel

Otto123 · 16 Mai 2019, 09:47:40

Zitat von: Ma_Bo am 16 Mai 2019, 03:14:23
Der Fehler kann evtl. daher kommen, dass die Reihenfolge in der Config nicht stimmt.

Erst sollte das IO kommen und dann die HM Geräte.

Zitat aus dem Wiki: (https://wiki.fhem.de/wiki/Virtueller_Controller_VCCU)

Grüße Marcel

Moin,

kann es eigentlich nicht, denn erstens hat er keine VCCU und zweitens müsste dann der Fehler auch beim erneuten restart kommen.
Ich dachte auch an die Reihenfolge, aber dann müsste ja zusätzlich ein Initialisierungsproblem / Zeitproblem beim Start vorliegen, welches bei einem restart nicht auftritt. Wenn das so ist, dürfte die Reihenfolge wieder keine Rolle spielen.

Zumal der IO im Netzwerk hängt und nicht durch "Power on" initialisiert wird beim Start.
Und der Fehler ja nicht einfach beim Start im Log steht, sondern beim Schalten des Gerätes auftritt. An der Stelle darf die Reihenfolge keine Rolle mehr spielen.

Was noch sein kann: FHEM wird so schnell gestartet, dass das Netzwerk noch nicht da ist und der esp-link noch nicht erreicht werden kann. Sollte man dann auch durch ein reopen des HMUART lösen können, das macht der aber eigentlich automatisch mehrfach.

Wie ist denn der Zustand (bitte ein list HM_Gateway) des HMUART wenn dieser Fehler auftritt?

Gruß Otto

Beta-User · 16 Mai 2019, 10:02:56

Soweit ich mich entsinne, gab es zu dem "Reihenfolgethema" mal eine Art "genereller Aufräumaktion" (so ca. vor zwei Jahren). Seitdem wird nach dem IO bei fast allen Modulen erst gesucht, wenn der "erste Durchlauf" durch die Konfiguration erfolgt ist.

Wird dabei aber (z.B. wg. irgendwelcher Neztwerkthemen) das (einzige) IO nicht sauber initialisiert (z.B. weil es erst noch aus einer Art Schlafmodus aufwachen muß), gibt es diese Art Problem.

U.a. deswegen macht es eventuell Sinn, eine VCCU "dazwischenzuschalten", die dann - zumindest für alles, was "logisch dahinter" liegt - ein fake-IO zur Verfügung stellt und die echten IOs verwaltet.

Aber grundsätzlich (selbst wenn das nicht zielführend sein sollte): Es macht für CUL_HM nach Aussage des zuständigen Maintainers immer Sinn, eine VCCU einzurichten. Was spricht also gegen einen Test?

Otto123 · 16 Mai 2019, 10:15:09

Zitat von: Beta-User am 16 Mai 2019, 10:02:56

Es macht für CUL_HM nach Aussage des zuständigen Maintainers immer Sinn, eine VCCU einzurichten. Was spricht also gegen einen Test?

Gar nichts! Dagegen wollte ich nichts sagen!
Ich wollte der Annahme widersprechen, es hat was mit dem im VCCU Wikiartikel behandelten Reihenfolgethema zu tun. Das äußert sich anders.

cs-online · 25 Mai 2019, 17:42:10

Hallo zusammen,

sorry,dass ich erst jetzt antworte, wir waren eine Woche lang auf einer schönen Insel mit drei Buchstaben...

Leider tritt der Fehler nicht bei jedem Neustart auf, so konnte ich den jetzt gerade nicht nachstellen, trotz mehrfachen Versuchen. Bleibt leider nur abzuwarten, bis das wieder auftritt. würde mich dann wieder bei euch melden.

Bis dahin erstmal vielen Dank für die Diskussionen.

Grüße

Christian

cs-online · 08 Juni 2019, 19:25:11

Hallo zusammen,

heute ist der Fehler wieder aufgetreten. Hier ein List vom HM_Gateway:

Code Auswählen

Internals:
   AssignedPeerCnt 1
   CNT        131
   Clients    :CUL_HM:
   DEF        uart://192.168.2.125:23
   DEVCNT     131
   DevState   99
   DevType    UART
   DeviceName 192.168.2.125:23
   FD         162
   FUUID      5c477543-f33f-1755-32d2-0919da8b20955b98
   LastOpen   1559997090.37408
   NAME       HM_Gateway
   NOTIFYDEV  global
   NR         576
   NTFY_ORDER 50-HM_Gateway
   PARTIAL    
   RAWMSG     040200
   RSSI       -45
   STATE      opened
   TYPE       HMUARTLGW
   XmitOpen   1
   model      HM-MOD-UART
   msgLoadCurrent 0
   msgLoadHistory 0/0/0/0/0/0/0/0/0/0/0/0
   msgLoadHistoryAbs 0/0/0/0/0/0/0/0/0/0/0/0/0
   owner      424242
   Helper:
     CreditTimer 1133
     FW         66561
     Initialized 1
     SendCnt    4
     AckPending:
       148:
         cmd        02000000A4800242424233767600
         dst        1
         frame      FD0010019402000000A48002424242337676000260
         time       1560010712.78221
     LastSendLen:
       3
       3
     Log:
       IDs:
     PendingCMD:
     RoundTrip:
       Delay      0.0077519416809082
     loadLvl:
       lastHistory 1560014205.86676
   MatchList:
     1:CUL_HM   ^A......................
   Peers:
     337676     +337676,00,00,00
   READINGS:
     2019-06-08 14:31:41   D-HMIdAssigned  424242
     2019-06-08 14:31:41   D-HMIdOriginal  58341D
     2019-06-08 14:31:44   D-firmware      1.4.1
     2019-06-08 14:31:45   D-serialNr      OEQ0304477
     2019-06-08 14:30:55   D-type          HM-MOD-UART
     2019-06-08 14:31:46   cond            ok
     2019-06-08 14:31:46   load            0
     2019-06-08 14:31:46   loadLvl         low
     2019-06-08 14:31:30   state           opened
   helper:
Attributes:
   dutyCycle  0
   group      Funk_Gateways
   hmId       424242
   icon       cul_868
   room       Schnittstellen
   verbose    1

und hier eins von einem Actor, der den Fehler bei "statusRequest" hat:

Code Auswählen

Internals:
   DEF        3376DA
   FUUID      5c477531-f33f-1755-ccf3-74b0febc24029576
   IODev      
   IODevMissing 1
   IODevName  HM_Gateway
   NAME       Rolladen_Esszimmer_Links
   NOTIFYDEV  global
   NR         36
   STATE      on
   TYPE       CUL_HM
   chanNo     01
   READINGS:
     2019-06-08 08:53:12   CommandAccepted yes
     2018-02-11 21:55:14   D-firmware      2.3
     2018-02-11 21:55:14   D-serialNr      LEQ1436933
     2018-02-11 21:56:06   PairedTo        0x424242
     2018-02-11 21:56:08   R-driveDown     25 s
     2018-02-11 21:56:08   R-driveTurn     0.5 s
     2018-02-11 21:56:08   R-driveUp       26 s
     2018-02-11 21:56:06   R-pairCentral   0x424242
     2018-02-11 21:56:08   R-sign          off
     2018-02-11 21:56:06   RegL_00.        02:01 0A:42 0B:42 0C:42 15:FF 18:00 00:00
     2018-02-11 21:56:08   RegL_01.        08:00 09:00 0A:00 0B:00 0C:FA 0D:01 0E:04 0F:05 10:00  30:06 57:24 00:00
     2019-06-08 08:53:28   deviceMsg       on (to HM_Gateway)
     2019-06-08 08:53:28   level           100
     2019-06-08 08:53:28   motor           stop:on
     2019-06-08 08:53:28   pct             100
     2019-06-08 08:53:28   recentStateType info
     2019-06-08 08:53:12   rssi_HM_Gateway -72
     2019-06-08 08:53:28   rssi_at_HM_Gateway -41
     2019-06-08 08:53:28   state           on
     2019-06-08 08:53:28   timedOn         off
   helper:
     HM_CMDNR   124
     mId        0005
     peerFriend peerSens,peerVirt
     peerOpt    3:blindActuator
     regLst     0,1,3p
     rxType     1
     expert:
       def        1
       det        0
       raw        1
       tpl        0
     io:
       newChn     +3376DA,00,00,00
       prefIO     
       rxt        0
       vccu       
       p:
         3376DA
         00
         00
         00
     mRssi:
       mNo        
     prt:
       bErr       0
       sProc      0
     q:
       qReqConf   
       qReqStat   00
     role:
       chn        1
       dev        1
       prs        1
Attributes:
   IODev      HM_Gateway
   alexaName  Rolladen
   alexaRoom  Esszimmer
   autoReadReg 4_reqStatus
   expert     2_full
   firmware   2.3
   genericDeviceType blind
   group      Rolladen
   model      HM-LC-BL1PBU-FM
   peerIDs    00000000,
   room       Rolladen,Esszimmer
   rssiLog    1
   serialNr   LEQ1436933
   subType    blindActuator
   userattr   room_map structexclude
   webCmd     statusRequest:on:off:up:down:stop:50

Merkwürdigerweise gibt es einen Actor, der funktioniert. Hier das List von dem:

Code Auswählen

Internals:
   DEF        337676
   FUUID      5c477531-f33f-1755-2319-33de8e09de787326
   HM_Gateway_MSGCNT 12
   HM_Gateway_RAWMSG 0501002DAEA41033767642424206018200
   HM_Gateway_RSSI -45
   HM_Gateway_TIME 2019-06-08 19:23:07
   IODev      HM_Gateway
   IODevMissing 1
   IODevName  HM_Gateway
   LASTInputDev HM_Gateway
   MSGCNT     12
   NAME       Rolladen_Wohnzimmer
   NOTIFYDEV  global
   NR         30
   STATE      65
   TYPE       CUL_HM
   chanNo     01
   lastMsg    No:AE - t:10 s:337676 d:424242 06018200
   protLastRcv 2019-06-08 19:23:07
   protRcv    12 last_at:2019-06-08 19:23:07
   protSnd    14 last_at:2019-06-08 19:23:07
   protState  CMDs_done
   rssi_HM_Gateway cnt:6 min:-53 max:-50 avg:-51.16 lst:-51 
   rssi_at_HM_Gateway cnt:12 min:-50 max:-44 avg:-46.66 lst:-45 
   READINGS:
     2019-06-08 19:23:02   CommandAccepted yes
     2018-06-23 17:33:44   D-firmware      2.3
     2018-06-23 17:33:44   D-serialNr      LEQ1436861
     2019-05-04 16:12:31   PairedTo        0x424242
     2018-06-23 17:34:12   R-driveDown     31 s
     2018-06-23 17:34:12   R-driveTurn     0.5 s
     2018-06-23 17:34:12   R-driveUp       31 s
     2018-06-23 17:34:11   R-pairCentral   0x424242
     2018-06-23 17:34:12   R-sign          off
     2019-05-04 16:12:31   RegL_00.        00:00 02:01 0A:42 0B:42 0C:42 15:FF 18:00
     2019-05-04 16:12:32   RegL_01.        00:00 08:00 09:00 0A:00 0B:01 0C:36 0D:01 0E:36 0F:05 10:00 30:06 57:24
     2019-06-08 19:23:07   deviceMsg       65 (to HM_Gateway)
     2019-06-08 19:23:07   level           65
     2019-06-08 19:23:07   motor           stop:65
     2019-06-08 19:23:07   pct             65
     2019-05-04 16:11:47   powerOn         2019-05-04 16:11:47
     2019-06-08 19:23:07   recentStateType info
     2019-06-08 19:23:02   rssi_HM_Gateway -51
     2019-06-08 19:23:07   rssi_at_HM_Gateway -45
     2019-06-08 19:23:07   state           65
     2019-06-08 19:23:07   timedOn         off
   helper:
     HM_CMDNR   174
     cSnd       11424242337676020196,11424242337676020182
     dlvlCmd    ++A011424242337676020182
     mId        0005
     peerFriend peerSens,peerVirt
     peerOpt    3:blindActuator
     regLst     0,1,3p
     rxType     1
     supp_Pair_Rep 0
     dir:
       cur        stop
       rct        down
     expert:
       def        1
       det        0
       raw        1
       tpl        0
     io:
       newChn     +337676,00,00,00
       nextSend   1560014588.10231
       prefIO     
       rxt        0
       vccu       
       p:
         337676
         00
         00
         00
     mRssi:
       mNo        AE
       io:
         HM_Gateway:
           -37
           -37
     prt:
       bErr       0
       sProc      0
       rspWait:
     q:
       qReqConf   
       qReqStat   
     role:
       chn        1
       dev        1
       prs        1
     rpt:
       IO         HM_Gateway
       flg        A
       ts         1560014587.9349
       ack:
         HASH(0x1168df0)
         AE800242424233767600
     rssi:
       HM_Gateway:
         avg        -51.1666666666667
         cnt        6
         lst        -51
         max        -50
         min        -53
       at_HM_Gateway:
         avg        -46.6666666666667
         cnt        12
         lst        -45
         max        -44
         min        -50
Attributes:
   IODev      HM_Gateway
   alexaName  rollladen
   alexaRoom  wohnzimmer
   autoReadReg 4_reqStatus
   expert     2_full
   firmware   2.3
   genericDeviceType blind
   group      Rolladen
   icon       fts_shutter_10
   model      HM-LC-BL1PBU-FM
   peerIDs    00000000,
   room       Alexa,Rolladen,Wohnzimmer
   rssiLog    1
   serialNr   LEQ1436861
   subType    blindActuator
   userattr   room_map structexclude
   webCmd     statusRequest:on:off:up:down:stop:65

Könnt Ihr da irgendwas erkennen ?

nach erneutem shutdown restart geht alles wieder.... (wie meistens)

Grüße Christian

LuckyDay · 08 Juni 2019, 19:50:24

Uart

Code Auswählen

2019-06-08 14:31:46 cond ok

Fehler

Code Auswählen

2019-06-08 08:53:28 deviceMsg on (to HM_Gateway)
ok

Code Auswählen

2019-06-08 19:23:07 deviceMsg 65 (to HM_Gateway)

Für mich passen deine drei Lists nicht zusammen
zumal dein UART um 14:31 cond ok hat, also hat sich neu mit Fhem verbunden.

hast du ein Wlan Problem? wann war dein restart? usw, wo ist das Fhemlog zum restart?
wo ist überhaupt der Fehler

Zitatder den Fehler bei "statusRequest"

in deinen List's?

cs-online · 08 Juni 2019, 20:56:39

also die Lists sind alle direkt hintereinander gemacht worden und sind vollständig so wie FHEM das ausgegeben hat. Der Fehler, der dann kommt, wenn man etwas schalten will, also in diesem Fall die Rolläden, egal ob nur StatusRequest oder on/off ist "no IO device identified", was in einem Popup erscheint. Log (das meiste ist auf Verbose = 0 oder 1 gestellt) vom Neustart:

Code Auswählen

2019.06.08 14:22:00 1: RMDIR: ./restoreDir/save/2019-05-12
2019.06.08 14:30:39 0: [Freezemon] myfreezemon: Unwrapping CallFn
2019.06.08 14:30:39 0: [Freezemon] myfreezemon: Unwrapping AnalyzeCommand
2019.06.08 14:30:39 0: [Freezemon] myfreezemon: Unwrapping Log3
2019.06.08 14:30:39 1: Timeout for PRESENCE_DoLocalPingScan reached, terminated process 32054
2019.06.08 14:30:40 1: Including fhem.cfg
2019.06.08 14:30:51 1: Including ./FHEM/16er_Relais.cfg
2019.06.08 14:30:55 1: Including ./FHEM/8er_Relais.cfg
2019.06.08 14:30:56 0: [echodevice] load ECHO Device ECHO_90F00818718704G4
2019.06.08 14:30:56 0: [echodevice] load ECHO Device ECHO_G090LF1174170MR2
2019.06.08 14:30:56 0: [echodevice] load ECHO Device ECHO_6b9266c761a544a897c63a40e8be4b9b
2019.06.08 14:30:56 0: [echodevice] load ECHO Device ECHO_G090LA09735203ND
2019.06.08 14:30:57 0: [echodevice] load ECHO Device ECHO_G090LF1180520A07
2019.06.08 14:30:58 0: [echodevice] load ECHO Device ECHO_G090U5078413386U
2019.06.08 14:30:58 1: Including ./FHEM/Funkdimmer.cfg
2019.06.08 14:30:58 1: Including ./FHEM/Signalduino.cfg
2019.06.08 14:30:58 1: SIGNALduino/define: /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A50478VZ-if00-port0@57600
2019.06.08 14:30:58 1: SIGNALduino/init: /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A50478VZ-if00-port0@57600
2019.06.08 14:30:59 0: [echodevice] load ECHO Device ECHO_709003094507017W
2019.06.08 14:30:59 0: [echodevice] load ECHO Device ECHO_G070L80773870TRH
2019.06.08 14:30:59 0: [echodevice] load ECHO Device ECHO_afdcadc144a34f8e9cdbccfbe68454e6
2019.06.08 14:30:59 1: Including ./FHEM/GAEBUS.cfg
2019.06.08 14:30:59 1: Including ./FHEM/Gewaechshaus.cfg
2019.06.08 14:30:59 1: Including ./log/fhem.save

WLAN-Probleme gibt's eigentlich nicht, der HM-MOD-UART hängt an nem ESP8266 über WLAN direkt neben der Fritzbox, der FHEM-Server hängt über LAN-Kabel an der Fritzbox.

Merkwürdigerweise war ja einer von 7 Rollladenschaltern ohne Fehlermeldung und liess sich auch steuern, bei den anderen 6 der Fehler (das ist mir heute aber auch zum ersten mal aufgefallen)...

Bin da etwas ratlos. Den HM-MOD-UART habe ich auch schon samt ESP8266 getauscht (da habe ich zwei von), mit dem tritt der Fehler gefühlt seltener auf, als mit dem anderen, kann aber auch Zufall sein.

Grüße Christian