Eins von zwei HM-Dis-WM55 paired nicht, RESPONSE TIMEOUT:RegisterRead

[noansi]

Hallo Joachim,

in Deinen Logs sehe ich nicht die Rohdaten von HM CFGUSB. Beim dem fehlt der passende verbose.

Aber mir wäre es hilfreich, wenn Du parallel auf Deinem Testsystem mit verbose 4 beim "Spezial CUL" den ganzen Vorgang vom scharfen System loggen/mitlauschen könntest. Dann habe ich auch gleich alle Timing Infos.

Danke!

@Marcus: Ja, nach dem Flashen hat sich die /dev/ttyAMA* Schnittstelle geändert. Das kann sich ggf. auch nach einem Reboot des Systems nochmal ändern. Mit

Code Auswählen Erweitern

dmesg
auf einer Linux Konsole/Terminal kannst Du herraus lesen, auf welcher Schnittstelle das device landet.

Gruß, Ansgar.

[MadMax-FHEM]

Hi Ansgar,

hab ich mir schon gedacht, war mir auch zu wenig...

Hatte aber verbose 4 bei global und dem hmusb...

Soll ich auf 5 gehen?
Oder fehlt noch wo was?
Pairing stosse ich von der vccu aus an...

Hab heute Nachmitrag/Abend noch mal Zeit was zu testen...

Werde dann auch mal auf meinem Testsystem (spezial-CUL) pairen...

Wichtig für mich: welche Einstellungen wo, damit du die notwendigen Infos bekommst...

Gruß, Joachim

[KillVirus]

Hallo Ansgar,

danke für deine Nachricht. Mein device stimmt.
Ich wollte insbesondere wissen, ob du sonst etwas verändert hast. Du hast je geflashed um das Problem zu lösen nehme ich an. Das Problem bestand also schon vorher.

Bei dir ging es also einfach mit neuem flashen des CUL und danach anpassen des device?

Dank & Gruß Marcus

[noansi]

Hallo Joachim,

ja, versuch es mal mit verbose 5 auf dem scharfen System. Ich sehe nicht, was gesendet/empfangen wird.

Auf dem Testsystem kannst Du natürlich auch mal pairen und loggen, das würde das Fehlverhalten aufzeichnen.
Aber eigentlich interessiert mich, wie es mt hmusb "richtig" abläuft und nur wenn Du auf dem Testsystem mit verbose 4 bei CUL mitloggst, was auf dem scharfen System im Äther passiert sehe ich was vernünftiges.

@Marcus: In der Timestamp Firmware habe ich eine USB Seriennummer implementiert. Die kann man bei Bedarf beim Kompilieren auch je CUL individuell einstellen. Damit ist eine eindeutige Zuordnung mehrer CULs anhand der Seriennummer möglich.
Offenbar führt das ggf. zu einer Änderung der automatischen Schnittstellenzuordnung. Damit musst Du also ggf. die Schnittstelle in der fhem.cfg für den CUL anpassen, um CUL wieder nutzen zu können. Nach einen Systemneustart kann die Zuordnung auch wieder anders sein.
Mit der "/etc/udev/rules.d/99-usb-serial.rules" kannst Du die USB Seriennummer nutzen, um einen eindeutigen Schnittstellen link zu erzeugen.

Code Auswählen Erweitern

#/etc/udev/rules.d/99-usb-serial.rules
#CUL 868MHz
SUBSYSTEM=="tty", ATTRS{idVendor}=="03eb", ATTRS{idProduct}=="204b", ATTRS{serial}=="868000", SYMLINK+="CUL868_0"
damit in fhem.cfg

Code Auswählen Erweitern

define CUL_HM868 CUL /dev/CUL868_0@12000000 1034
Auf diese Art habe ich 2 CULs an meinem RasPi zu eindeutigen Schnittstellen bringen können.
Dein eigentliches Problem mit dem Display ist dann der nächste Akt. Und das scheint noch nicht gelöst.

Gruß, Ansgar.

[MadMax-FHEM]

Hi Ansgar,

so ich hab mein Hauptsystem mit dem hmusb mal "leer geräumt", damit nicht so viel unnützes Zeugs drin steht...

Hier das Log von Pairing und getConfig:

Code Auswählen Erweitern


2016.09.11 01:22:03.536 5: Cmd: >set vccu hmPairForSec 60<
2016.09.11 01:22:03.538 3: CUL_HM set vccu hmPairForSec 60
2016.09.11 01:22:03.575 4: WEB_192.168.1.72_48234 GET /fhem?detail=vccu&fw_id=; BUFLEN:0
2016.09.11 01:22:03.611 4: name: /fhem?detail=vccu&fw_id= / RL:5333 / text/html; charset=UTF-8 / Content-Encoding: gzip
/
2016.09.11 01:22:04.229 4: WEB_192.168.1.72_48234 GET /fhem?cmd={ReadingsVal(%22vccu%22,%22virtual%22,%22%22)}&XHR=1; BUFLEN:0
2016.09.11 01:22:04.230 5: Cmd: >{ReadingsVal("vccu","virtual","")}<
2016.09.11 01:22:04.238 4: name: /fhem?cmd={ReadingsVal(%22vccu%22,%22virtual%22,%22%22)}&XHR=1 / RL:21 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2016.09.11 01:22:04.245 4: WEB_192.168.1.72_48234 GET /fhem?cmd={AttrVal(%22vccu%22,%22room%22,%22%22)}&XHR=1; BUFLEN:0
2016.09.11 01:22:04.246 5: Cmd: >{AttrVal("vccu","room","")}<
2016.09.11 01:22:04.254 4: name: /fhem?cmd={AttrVal(%22vccu%22,%22room%22,%22%22)}&XHR=1 / RL:21 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2016.09.11 01:22:04.364 4: WEB_192.168.1.72_48234 GET /fhem?XHR=1&inform=type=status;filter=vccu;since=1473549722;fmt=JSON&fw_id=62×tamp=1473549724271; BUFLEN:0
2016.09.11 01:22:04.940 5: HMLAN/RAW: /E3227F4,0000,0001D28F,FF,FFBE,F3865A3227F4000000910139

2016.09.11 01:22:04.941 5: HMLAN_Parse: hmusb R:E3227F4   stat:0000 t:0001D28F d:FF r:FFBE     m:F3 865A 3227F4 000000 910139
2016.09.11 01:22:04.942 5: hmusb dispatch A0CF3865A3227F4000000910139::-66:hmusb
2016.09.11 01:22:05.644 5: HMLAN/RAW: /E2B8E86,0000,0001D532,FF,FFBD,2886102B8E860000000A99020B0040

2016.09.11 01:22:05.645 5: HMLAN_Parse: hmusb R:E2B8E86   stat:0000 t:0001D532 d:FF r:FFBD     m:28 8610 2B8E86 000000 0A99020B0040
2016.09.11 01:22:05.646 5: hmusb dispatch A0F2886102B8E860000000A99020B0040::-67:hmusb
2016.09.11 01:22:09.036 5: HMLAN/RAW: /E3515DA,0000,0001E27F,FF,FFDA,0184003515DA0000001000D34D45513030323237363812110000

2016.09.11 01:22:09.042 5: HMLAN_Parse: hmusb R:E3515DA   stat:0000 t:0001E27F d:FF r:FFDA     m:01 8400 3515DA 000000 1000D34D45513030323237363812110000
2016.09.11 01:22:09.043 5: hmusb dispatch A1A0184003515DA0000001000D34D45513030323237363812110000::-38:hmusb
2016.09.11 01:22:09.044 2: CUL_HM Unknown device HM_3515DA is now defined
2016.09.11 01:22:09.044 5: Triggering global (1 changes)
2016.09.11 01:22:09.045 5: Starting notify loop for global, first event UNDEFINED HM_3515DA CUL_HM 3515DA
2016.09.11 01:22:09.047 2: autocreate: define HM_3515DA CUL_HM 3515DA
2016.09.11 01:22:09.048 5: Triggering global (2 changes)
2016.09.11 01:22:09.050 2: autocreate: define FileLog_HM_3515DA FileLog ./log/HM_3515DA-%Y.log HM_3515DA
2016.09.11 01:22:09.052 5: Triggering global (3 changes)
2016.09.11 01:22:09.059 5: Triggering global (1 changes)
2016.09.11 01:22:09.060 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_01
2016.09.11 01:22:09.063 5: Triggering global (1 changes)
2016.09.11 01:22:09.063 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_02
2016.09.11 01:22:09.066 5: Triggering global (1 changes)
2016.09.11 01:22:09.067 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_03
2016.09.11 01:22:09.070 5: Triggering global (1 changes)
2016.09.11 01:22:09.070 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_04
2016.09.11 01:22:09.073 5: Triggering global (1 changes)
2016.09.11 01:22:09.074 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_05
2016.09.11 01:22:09.077 5: Triggering global (1 changes)
2016.09.11 01:22:09.077 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_06
2016.09.11 01:22:09.080 5: Triggering global (1 changes)
2016.09.11 01:22:09.081 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_07
2016.09.11 01:22:09.084 5: Triggering global (1 changes)
2016.09.11 01:22:09.084 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_08
2016.09.11 01:22:09.087 5: Triggering global (1 changes)
2016.09.11 01:22:09.088 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_09
2016.09.11 01:22:09.091 5: Triggering global (1 changes)
2016.09.11 01:22:09.092 5: Starting notify loop for global, first event DEFINED HM_3515DA_Dis_10
2016.09.11 01:22:09.094 3: CUL_HM pair: HM_3515DA pushButton, model HM-Dis-WM55 serialNr
2016.09.11 01:22:09.099 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:1
2016.09.11 01:22:09.100 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:2
2016.09.11 01:22:09.100 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:3
2016.09.11 01:22:09.144 5: HMLAN_Send:  hmusb S:S16687EA5 stat:  00 t:00000000 d:01 r:16687EA5 m:16 A001 AFFE11 3515DA 00050000000000
2016.09.11 01:22:09.146 5: CUL_HM HM_3515DA protEvent:CMDs_processing... pending:2
2016.09.11 01:22:09.148 5: Triggering HM_3515DA (3 changes)
2016.09.11 01:22:09.149 5: Starting notify loop for HM_3515DA, first event D-firmware: 1.0
2016.09.11 01:22:09.324 5: HMLAN/RAW: /E3515DA,0100,0001E39F,FF,FFDA,16A0023515DAAFFE11042C3A18182C3A00

2016.09.11 01:22:09.326 5: HMLAN_Parse: hmusb R:E3515DA   stat:0100 t:0001E39F d:FF r:FFDA     m:16 A002 3515DA AFFE11 042C3A18182C3A00
2016.09.11 01:22:09.326 5: hmusb dispatch A1116A0023515DAAFFE11042C3A18182C3A00:AESpending:-38:hmusb
2016.09.11 01:22:09.329 5: Triggering HM_3515DA (2 changes)
2016.09.11 01:22:09.330 5: Starting notify loop for HM_3515DA, first event aesCommToDev: pending
2016.09.11 01:22:09.580 5: HMLAN/RAW: /R16687EA5,0021,0001E3A4,00,FFDA,1680023515DAAFFE1100E87EED8E

2016.09.11 01:22:09.581 5: HMLAN_Parse: hmusb R:R16687EA5 stat:0021 t:0001E3A4 d:00 r:FFDA     m:16 8002 3515DA AFFE11 00E87EED8E
2016.09.11 01:22:09.582 5: hmusb dispatch A0E1680023515DAAFFE1100E87EED8E:AESCom-ok:-38:hmusb
2016.09.11 01:22:09.587 5: HMLAN_Send:  hmusb S:S1668808A stat:  00 t:00000000 d:01 r:1668808A m:17 A001 AFFE11 3515DA 000802010AAF0BFE0C11
2016.09.11 01:22:09.590 5: CUL_HM HM_3515DA protEvent:CMDs_processing... pending:1
2016.09.11 01:22:09.593 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:09.593 5: Starting notify loop for HM_3515DA, first event aesCommToDev: ok
2016.09.11 01:22:09.996 5: HMLAN/RAW: /E3515DA,0100,0001E637,FF,FFD8,17A0023515DAAFFE11046CB898966CB800

2016.09.11 01:22:09.997 5: HMLAN_Parse: hmusb R:E3515DA   stat:0100 t:0001E637 d:FF r:FFD8     m:17 A002 3515DA AFFE11 046CB898966CB800
2016.09.11 01:22:09.998 5: hmusb dispatch A1117A0023515DAAFFE11046CB898966CB800:AESpending:-40:hmusb
2016.09.11 01:22:10.001 5: Triggering HM_3515DA (2 changes)
2016.09.11 01:22:10.002 5: Starting notify loop for HM_3515DA, first event aesCommToDev: pending
2016.09.11 01:22:10.252 5: HMLAN/RAW: /R1668808A,0021,0001E63C,00,FFCE,1780023515DAAFFE11000C7FE718

2016.09.11 01:22:10.253 5: HMLAN_Parse: hmusb R:R1668808A stat:0021 t:0001E63C d:00 r:FFCE     m:17 8002 3515DA AFFE11 000C7FE718
2016.09.11 01:22:10.254 5: hmusb dispatch A0E1780023515DAAFFE11000C7FE718:AESCom-ok:-50:hmusb
2016.09.11 01:22:10.259 5: HMLAN_Send:  hmusb S:S16688329 stat:  00 t:00000000 d:01 r:16688329 m:18 A001 AFFE11 3515DA 0006
2016.09.11 01:22:10.262 5: CUL_HM HM_3515DA protEvent:CMDs_processing... pending:0
2016.09.11 01:22:10.265 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:10.265 5: Starting notify loop for HM_3515DA, first event aesCommToDev: ok
2016.09.11 01:22:10.669 5: HMLAN/RAW: /E3515DA,0100,0001E8C6,FF,FFCC,18A0023515DAAFFE1104DA3A2119DA3A00

2016.09.11 01:22:10.670 5: HMLAN_Parse: hmusb R:E3515DA   stat:0100 t:0001E8C6 d:FF r:FFCC     m:18 A002 3515DA AFFE11 04DA3A2119DA3A00
2016.09.11 01:22:10.670 5: hmusb dispatch A1118A0023515DAAFFE1104DA3A2119DA3A00:AESpending:-52:hmusb
2016.09.11 01:22:10.673 5: Triggering HM_3515DA (2 changes)
2016.09.11 01:22:10.674 5: Starting notify loop for HM_3515DA, first event aesCommToDev: pending
2016.09.11 01:22:10.925 5: HMLAN/RAW: /R16688329,0021,0001E8CB,00,FFCB,1880023515DAAFFE1100053E3505

2016.09.11 01:22:10.925 5: HMLAN_Parse: hmusb R:R16688329 stat:0021 t:0001E8CB d:00 r:FFCB     m:18 8002 3515DA AFFE11 00053E3505
2016.09.11 01:22:10.926 5: hmusb dispatch A0E1880023515DAAFFE1100053E3505:AESCom-ok:-53:hmusb
2016.09.11 01:22:10.930 5: CUL_HM HM_3515DA protEvent:CMDs_done
2016.09.11 01:22:10.933 5: Triggering HM_3515DA (2 changes)
2016.09.11 01:22:10.934 5: Starting notify loop for HM_3515DA, first event aesCommToDev: ok
2016.09.11 01:22:11.795 5: HMLAN_Send:  hmusb I:K
2016.09.11 01:22:12.365 5: HMLAN/RAW: /HHM-LAN-IF,03C7,LEQ0659122,2CC6D3,AFFE11,0001EF86,0000

2016.09.11 01:22:12.366 5: HMLAN_Parse: hmusb V:03C7 sNo:LEQ0659122 d:2CC6D3 O:AFFE11 t:0001EF86 IDcnt:0000 L:0 %
2016.09.11 01:22:12.367 5: Triggering hmusb (1 changes)
2016.09.11 01:22:12.367 5: Starting notify loop for hmusb, first event loadLvl: low
2016.09.11 01:22:14.096 5: HMLAN_Send:  hmusb I:+3515DA,00,00,00
2016.09.11 01:22:16.845 5: HMLAN/RAW: /E3229B5,0000,00020101,FF,FFD0,0F84703229B500000000FE39

2016.09.11 01:22:16.846 5: HMLAN_Parse: hmusb R:E3229B5   stat:0000 t:00020101 d:FF r:FFD0     m:0F 8470 3229B5 000000 00FE39
2016.09.11 01:22:16.847 5: hmusb dispatch A0C0F84703229B500000000FE39::-48:hmusb
2016.09.11 01:22:17.261 5: HMLAN/RAW: /E32185B,0000,0002029A,FF,FFE2,47865A32185B000000910837

2016.09.11 01:22:17.262 5: HMLAN_Parse: hmusb R:E32185B   stat:0000 t:0002029A d:FF r:FFE2     m:47 865A 32185B 000000 910837
2016.09.11 01:22:17.263 5: hmusb dispatch A0C47865A32185B000000910837::-30:hmusb
2016.09.11 01:22:19.735 4: Connection accepted from WEB_192.168.1.72_48236
2016.09.11 01:22:19.738 4: WEB_192.168.1.72_48236 POST /fhem?cmd=save&XHR=1&fw_id=62; BUFLEN:0
2016.09.11 01:22:19.739 5: Cmd: >save<
2016.09.11 01:22:19.739 5: Triggering global (1 changes)
2016.09.11 01:22:19.740 5: Starting notify loop for global, first event SAVE
2016.09.11 01:22:19.743 4: WriteStatefile HM_3515DA_Dis_01 peerList: Missing TIME, using current time
2016.09.11 01:22:19.778 4: name: /fhem?cmd=save&XHR=1&fw_id=62 / RL:52 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2016.09.11 01:22:20.260 4: HMLAN_ack: timeout - clear queue
2016.09.11 01:22:24.942 5: HMLAN/RAW: /E3227F4,0000,000220B0,FF,FFBF,F384703227F4000000010139

2016.09.11 01:22:24.949 5: HMLAN_Parse: hmusb R:E3227F4   stat:0000 t:000220B0 d:FF r:FFBF     m:F3 8470 3227F4 000000 010139
2016.09.11 01:22:24.950 5: hmusb dispatch A0CF384703227F4000000010139::-65:hmusb
2016.09.11 01:22:27.503 5: HMLAN/RAW: /E2BBF72,0000,00022AAF,FF,FFBA,0386702BBF7200000000D33E

2016.09.11 01:22:27.504 5: HMLAN_Parse: hmusb R:E2BBF72   stat:0000 t:00022AAF d:FF r:FFBA     m:03 8670 2BBF72 000000 00D33E
2016.09.11 01:22:27.504 5: hmusb dispatch A0C0386702BBF7200000000D33E::-70:hmusb
2016.09.11 01:22:27.855 5: HMLAN/RAW: /E322927,0000,00022BF8,FF,FFCB,A5865A32292700000060FF3A

2016.09.11 01:22:27.856 5: HMLAN_Parse: hmusb R:E322927   stat:0000 t:00022BF8 d:FF r:FFCB     m:A5 865A 322927 000000 60FF3A
2016.09.11 01:22:27.857 5: hmusb dispatch A0CA5865A32292700000060FF3A::-53:hmusb
2016.09.11 01:22:29.471 4: Connection closed for WEB_192.168.1.72_48234: EOF
2016.09.11 01:22:35.948 4: WEB_192.168.1.72_48236 GET /fhem; BUFLEN:0
2016.09.11 01:22:35.967 4: name: /fhem / RL:1134 / text/html; charset=UTF-8 / Content-Encoding: gzip
/
2016.09.11 01:22:36.653 4: WEB_192.168.1.72_48236 GET /fhem?XHR=1&inform=type=status;filter=room=Overview;since=1473549754;fmt=JSON&fw_id=75×tamp=1473549756558; BUFLEN:0
2016.09.11 01:22:36.795 5: HMLAN_Send:  hmusb I:K
2016.09.11 01:22:36.816 5: HMLAN/RAW: /HHM-LAN-IF,03C7,LEQ0659122,2CC6D3,AFFE11,00024F0D,0001

2016.09.11 01:22:36.817 5: HMLAN_Parse: hmusb V:03C7 sNo:LEQ0659122 d:2CC6D3 O:AFFE11 t:00024F0D IDcnt:0001 L:0 %
2016.09.11 01:22:36.818 5: Triggering hmusb (1 changes)
2016.09.11 01:22:36.818 5: Starting notify loop for hmusb, first event loadLvl: low
2016.09.11 01:22:37.264 5: HMLAN/RAW: /E32185B,0000,000250BB,FF,FFE2,47847032185B000000010837

2016.09.11 01:22:37.265 5: HMLAN_Parse: hmusb R:E32185B   stat:0000 t:000250BB d:FF r:FFE2     m:47 8470 32185B 000000 010837
2016.09.11 01:22:37.266 5: hmusb dispatch A0C47847032185B000000010837::-30:hmusb
2016.09.11 01:22:38.371 4: Connection closed for WEB_192.168.1.72_48236: EOF
2016.09.11 01:22:38.388 4: Connection accepted from WEB_192.168.1.72_48248
2016.09.11 01:22:38.392 4: WEB_192.168.1.72_48248 GET /fhem?room=CUL%5fHM; BUFLEN:0
2016.09.11 01:22:38.419 4: name: /fhem?room=CUL%5fHM / RL:1470 / text/html; charset=UTF-8 / Content-Encoding: gzip
/
2016.09.11 01:22:39.033 4: WEB_192.168.1.72_48248 GET /fhem?XHR=1&inform=type=status;filter=room=CUL%5fHM;since=1473549757;fmt=JSON&fw_id=76×tamp=1473549758940; BUFLEN:0
2016.09.11 01:22:42.242 4: Connection accepted from WEB_192.168.1.72_48250
2016.09.11 01:22:42.245 4: WEB_192.168.1.72_48250 POST /fhem?cmd.HM_3515DA=set%20HM_3515DA%20getConfig&room=CUL_HM&XHR=1&fw_id=76; BUFLEN:0
2016.09.11 01:22:42.247 5: Cmd: >set HM_3515DA getConfig<
2016.09.11 01:22:42.250 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.250 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.259 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:1
2016.09.11 01:22:42.261 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.262 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.268 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:2
2016.09.11 01:22:42.269 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.269 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.275 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:3
2016.09.11 01:22:42.276 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.277 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.282 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:4
2016.09.11 01:22:42.283 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.284 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.289 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:5
2016.09.11 01:22:42.290 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.291 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.297 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:6
2016.09.11 01:22:42.298 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.298 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.304 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:7
2016.09.11 01:22:42.305 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.306 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.310 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:8
2016.09.11 01:22:42.311 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.311 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.315 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:9
2016.09.11 01:22:42.316 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.317 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.321 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:10
2016.09.11 01:22:42.321 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.322 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.326 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:11
2016.09.11 01:22:42.327 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.327 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.331 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:12
2016.09.11 01:22:42.332 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.332 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.336 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:13
2016.09.11 01:22:42.337 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.337 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.341 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:14
2016.09.11 01:22:42.342 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.343 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.347 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:15
2016.09.11 01:22:42.347 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.348 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.352 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:16
2016.09.11 01:22:42.353 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.353 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.357 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:17
2016.09.11 01:22:42.358 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.358 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.362 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:18
2016.09.11 01:22:42.363 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.363 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.367 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:19
2016.09.11 01:22:42.368 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.369 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.373 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:20
2016.09.11 01:22:42.373 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:42.374 5: Starting notify loop for HM_3515DA, first event CMDs_pending
2016.09.11 01:22:42.378 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:21
2016.09.11 01:22:42.378 3: CUL_HM set HM_3515DA getConfig
2016.09.11 01:22:42.384 4: name: /fhem?cmd.HM_3515DA=set%20HM_3515DA%20getConfig&room=CUL_HM&XHR=1&fw_id=76 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip
/
2016.09.11 01:22:45.009 5: HMLAN/RAW: /E31D1FE,0000,00026EFB,FF,FFD8,EB865A31D1FE000000910633

2016.09.11 01:22:45.010 5: HMLAN_Parse: hmusb R:E31D1FE   stat:0000 t:00026EFB d:FF r:FFD8     m:EB 865A 31D1FE 000000 910633
2016.09.11 01:22:45.011 5: hmusb dispatch A0CEB865A31D1FE000000910633::-40:hmusb
2016.09.11 01:22:47.857 5: HMLAN/RAW: /E322927,0000,00027A18,FF,FFCB,A5847032292700000000FF3A

2016.09.11 01:22:47.862 5: HMLAN_Parse: hmusb R:E322927   stat:0000 t:00027A18 d:FF r:FFCB     m:A5 8470 322927 000000 00FF3A
2016.09.11 01:22:47.863 5: hmusb dispatch A0CA5847032292700000000FF3A::-53:hmusb
2016.09.11 01:22:48.561 5: HMLAN/RAW: /E3515DA,0000,00027CE2,FF,FFCC,02A2403515DAAFFE110201

2016.09.11 01:22:48.562 5: HMLAN_Parse: hmusb R:E3515DA   stat:0000 t:00027CE2 d:FF r:FFCC     m:02 A240 3515DA AFFE11 0201
2016.09.11 01:22:48.563 5: hmusb dispatch A0B02A2403515DAAFFE110201::-52:hmusb
2016.09.11 01:22:48.568 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:1
2016.09.11 01:22:48.568 5: CUL_HM HM_3515DA prep ACK for 02
2016.09.11 01:22:48.569 5: HMLAN: Skip ACK
2016.09.11 01:22:48.570 5: CUL_HM HM_3515DA protEvent:CMDs_processing... pending:1
2016.09.11 01:22:48.571 5: CUL_HM HM_3515DA sent ACK:2
2016.09.11 01:22:48.574 5: Triggering HM_3515DA (3 changes)
2016.09.11 01:22:48.575 5: Starting notify loop for HM_3515DA, first event battery: ok
2016.09.11 01:22:48.581 5: Triggering HM_3515DA_Dis_02 (3 changes)
2016.09.11 01:22:48.582 5: Starting notify loop for HM_3515DA_Dis_02, first event Short (to vccu)
2016.09.11 01:22:48.673 5: HMLAN_Send:  hmusb S:S16691937 stat:  00 t:00000000 d:01 r:16691937 m:03 A011 AFFE11 3515DA 8001020A0A0A0A0A0A03
2016.09.11 01:22:48.675 5: CUL_HM HM_3515DA protEvent:CMDs_processing... pending:0
2016.09.11 01:22:49.201 5: HMLAN/RAW: /R16691937,0001,00027F5F,FF,FFCC,0380023515DAAFFE1100

2016.09.11 01:22:49.202 5: HMLAN_Parse: hmusb R:R16691937 stat:0001 t:00027F5F d:FF r:FFCC     m:03 8002 3515DA AFFE11 00
2016.09.11 01:22:49.203 5: hmusb dispatch A0A0380023515DAAFFE1100::-52:hmusb
2016.09.11 01:22:49.207 5: CUL_HM HM_3515DA protEvent:CMDs_done
2016.09.11 01:22:49.210 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:49.210 5: Starting notify loop for HM_3515DA, first event CMDs_done
2016.09.11 01:22:54.482 5: HMLAN/RAW: /E2D9B77,0000,00029405,FF,FFC5,CF86102D9B770000000A98FE0B0040

2016.09.11 01:22:54.483 5: HMLAN_Parse: hmusb R:E2D9B77   stat:0000 t:00029405 d:FF r:FFC5     m:CF 8610 2D9B77 000000 0A98FE0B0040
2016.09.11 01:22:54.484 5: hmusb dispatch A0FCF86102D9B770000000A98FE0B0040::-59:hmusb
2016.09.11 01:22:55.282 5: HMLAN/RAW: /E3515DA,0000,00029730,FF,FFCC,03A2403515DAAFFE110202

2016.09.11 01:22:55.283 5: HMLAN_Parse: hmusb R:E3515DA   stat:0000 t:00029730 d:FF r:FFCC     m:03 A240 3515DA AFFE11 0202
2016.09.11 01:22:55.284 5: hmusb dispatch A0B03A2403515DAAFFE110202::-52:hmusb
2016.09.11 01:22:55.288 5: CUL_HM HM_3515DA protEvent:CMDs_pending pending:1
2016.09.11 01:22:55.289 5: CUL_HM HM_3515DA prep ACK for 02
2016.09.11 01:22:55.290 5: HMLAN: Skip ACK
2016.09.11 01:22:55.291 5: CUL_HM HM_3515DA protEvent:CMDs_processing... pending:1
2016.09.11 01:22:55.292 5: CUL_HM HM_3515DA sent ACK:2
2016.09.11 01:22:55.295 5: Triggering HM_3515DA (3 changes)
2016.09.11 01:22:55.296 5: Starting notify loop for HM_3515DA, first event battery: ok
2016.09.11 01:22:55.302 5: Triggering HM_3515DA_Dis_02 (3 changes)
2016.09.11 01:22:55.302 5: Starting notify loop for HM_3515DA_Dis_02, first event Short (to vccu)
2016.09.11 01:22:55.394 5: HMLAN_Send:  hmusb S:S16693378 stat:  00 t:00000000 d:01 r:16693378 m:04 A011 AFFE11 3515DA 8001020A0A0A0A0A0A03
2016.09.11 01:22:55.396 5: CUL_HM HM_3515DA protEvent:CMDs_processing... pending:0
2016.09.11 01:22:56.370 5: HMLAN/RAW: /R16693378,0001,00029B5E,FF,FFC7,0480023515DAAFFE1100

2016.09.11 01:22:56.371 5: HMLAN_Parse: hmusb R:R16693378 stat:0001 t:00029B5E d:FF r:FFC7     m:04 8002 3515DA AFFE11 00
2016.09.11 01:22:56.372 5: hmusb dispatch A0A0480023515DAAFFE1100::-57:hmusb
2016.09.11 01:22:56.376 5: CUL_HM HM_3515DA protEvent:CMDs_done
2016.09.11 01:22:56.379 5: Triggering HM_3515DA (1 changes)
2016.09.11 01:22:56.379 5: Starting notify loop for HM_3515DA, first event CMDs_done
2016.09.11 01:22:57.879 4: Connection closed for WEB_192.168.1.72_48248: EOF
2016.09.11 01:22:57.896 4: WEB_192.168.1.72_48250 GET /fhem/FileLog_logWrapper?dev=Logfile&type=text&file=fhem-2016-09.log; BUFLEN:0


Ich hoffe das hilft...

Falls ich noch mal Zeit hab schicke ich noch ein Log von meinem Testsystem mit dem "spezial-CUL"...

Gruß, Joachim

[noansi]

Hallo Joachim,

danke für das Log.

Ich vermisse allerdings das vollständige getConfig in der Ausführung darin.
Hast Du beim Device autoReadReg auf 5 und expert auf 2 gestellt, damit auch die Register gelesen werden?

Das mitloggen des Vorgangs auf dem Testsystem mit Spezial CUL auf verbose 4 würde mir dann auch alle eigenständigen Wiederholungen seitens HM_USB aufzeigen.

Gruß, Ansgar.

[MadMax-FHEM]

Hi Ansgar,

gerne.

Hmmm, ich stell die Werte ein (bzw. kontrolliere mal) und wiederhole...

Mache dann auch das selbe auf dem Testsystem/spezial-CUL...

Wird aber noch etwas dauern...

Gruß, Joachim

[noansi]

Hallo Joachim,

bitte auf dem Testsystem mitlauschen und loggen, wenn Du auf dem Hauptsystem loggst!

Hier https://forum.fhem.de/index.php/topic,24436.msg489979.html#msg489979 habe ich auch was neues zum Testen.  In meiner FHEM 5.7 Testumgebung läuft diese neue Version.

Gruß, Ansgar.

[MadMax-FHEM]

Hi Ansgar,

ah, ok.

Irgendwelche Einstellungen beim Testsystem (außer wie bisher beim Loggen)?

Autocreate nur auf einem System?
(Hauptsystem)

Gruß, Joachim

[noansi]

Hallo Joachim,

auf dem Testsystem nur verbose 4 beim spezial CUL zum mitlauschen, sonst nichts.

Gruß, Ansgar.

[KillVirus]

Hallo Ansgar,

danke für deine Nachricht.
Ich glaube nach wie vor nicht, dass das Device bei mir für Probleme sorgt. Ich habe ja nur Probleme beim Register lesen und pairen. Gewöhnliches Schalten von Autoren geht ja schon seit einem Jahr gut.
Danke für weitere Hinweise.

dmesg:

Code Auswählen Erweitern

[ 4088.329540] usb 1-1.5: USB disconnect, device number 5
[ 4088.329770] cdc_acm 1-1.5:1.0: failed to set dtr/rts
[ 4088.610037] usb 1-1.5: new full-speed USB device number 6 using dwc_otg
[ 4088.730983] usb 1-1.5: New USB device found, idVendor=03eb, idProduct=2ff4
[ 4088.731003] usb 1-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 4088.731014] usb 1-1.5: Product: ATm32U4DFU
[ 4088.731024] usb 1-1.5: Manufacturer: ATMEL
[ 4088.731048] usb 1-1.5: SerialNumber: 1.0.0
[ 4204.825067] usb 1-1.5: USB disconnect, device number 6
[ 5487.789585] usb 1-1.5: new full-speed USB device number 7 using dwc_otg
[ 5487.906388] usb 1-1.5: New USB device found, idVendor=03eb, idProduct=204b
[ 5487.906414] usb 1-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 5487.906430] usb 1-1.5: Product: CUL868
[ 5487.906445] usb 1-1.5: Manufacturer: busware.de
[ 5487.906460] usb 1-1.5: SerialNumber: 868000
[b][ 5487.909066] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device[/b]

fhem log:

Code Auswählen Erweitern

2016.09.14 13:44:18 0: Server shutdown
2016.09.14 13:44:20 1: Including fhem.cfg
2016.09.14 13:44:21 3: WEB: port 8083 opened
2016.09.14 13:44:21 3: WEBphone: port 8084 opened
2016.09.14 13:44:21 3: WEBtablet: port 8085 opened
2016.09.14 13:44:21 2: eventTypes: loaded 560 events from ./log/eventTypes.txt
[b]2016.09.14 13:44:21 3: Opening CUL1 device /dev/ttyACM0[/b]
2016.09.14 13:44:21 3: Setting CUL1 serial parameters to 9600,8,N,1
2016.09.14 13:44:22 1: CUL1 is VERSION_TS, V 99.75 CUL868, CUL_V3.4
2016.09.14 13:44:22 3: CUL1: Possible commands: BbCFiAZEGMKJUYRTVWXefmltux
2016.09.14 13:44:22 3: CUL1 device opened
2016.09.14 13:44:22 2: Switched CUL1 rfmode to HomeMatic
2016.09.14 13:44:24 1: Including ./log/fhem.save
2016.09.14 13:44:24 3: Device HM_2FDB94 added to ActionDetector with 000:10 time
2016.09.14 13:44:24 3: Device HM_38D85C added to ActionDetector with 000:10 time
2016.09.14 13:44:24 3: Device HM_4BE69C added to ActionDetector with 000:10 time
2016.09.14 13:44:24 3: Device Schaltsteckdose1 added to ActionDetector with 000:10 time
2016.09.14 13:44:24 2: SecurityCheck:  WEB,WEBtablet has no associated allowed device with basicAuth.  Restart FHEM for a new check if the problem is fixed, or set the global attribute motd to none to supress this message.
2016.09.14 13:44:24 0: Featurelevel: 5.7
2016.09.14 13:44:24 0: Server started with 58 defined entities (fhem.pl:12095/2016-08-30 perl:5.014002 os:linux user:fhem pid:11029)

[noansi]

Hallo Marcus,

Ich habe ja nur Probleme beim Register lesen und pairen

Gerade dabei kommt es auf das Timing an und auf die Einhaltung des Protokolls, dass aus mehreren Abfragen besteht.
Schalten ist meist nur ein Befehl an das device, auf den ein ACK vom device kommen muss. Von Sensoren kommen meißt nur "Broafcasts" aud die nicht geantwortet werden muss.

Beim Klingelsensor har das device ein abweichendes Verhalten bezüglich des Protokolls gehabt, washalb Martin eine Änderung eingebaut hat, die das beheben sollte.
Die Änderung besteht darin, wiederholte Requests, die Du mit dem Drücken der Pairing Taste auslöst, zu ignorieren.
D.h., wenn es beim ersten Drücken nicht klappt (Request wird nicht empfangen oder die Antwort auf den Request scheitert etc.), dann kannst Du lange weiter drücken, aber es passiert nichts mehr, bis vom device mal was anderes, als der Request kommt oder FHEM neu gestartet wird.

Ich habe in meinem Klingelsensorworkaroundversuch in meiner 10_CUL_HM.pm ein einmaliges Ignorieren eingebaut, so dass sich das bei nicht Klingelsensor devices beim zweiten Driuck der Pairing Taste wieder erholen sollte. Außerdem in meiner 00_CUL.pm ein einmaliges Wiederholen einer Anforderung an ein device auf die eine Ack Antwort angefordert wird, wenn das ACK nach Timeout ausbleibt. HMLAN macht diese Wiederholung wohl sogar 3-mal in der Firmware automatisch, ohne dass FHEM das mitbekommt, was wohl eigentlich auch nur für Empfangsprobleme aud device Seite gedacht gewesen ist.

Daher würde ich gerne ein Pairing und getConfig eines HMLAN hier mitgelauscht sehen, um zu sehen, ob es genau daran nun klemmen kann, weil wiederum dass device ggf. vom Protokoll abweicht und diese Wiederholung ggf. auch mehr als einmal braucht. Das würde Martin die Hinweise geben, was er ggf. korrigieren müßte.
Ggf. auch mir, wenn es devices gibt, die mehr als eine Wiederholung zwingend benötigen. Dann müßte die Wiederholung in die CUL Firmware rein, da Timeout-Timing über FHEM dann zu kritisch wird.

Gruß,

Ansgar.

[MadMax-FHEM]

Daher würde ich gerne ein Pairing und getConfig eines HMLAN hier mitgelauscht sehen, um zu sehen, ob es genau daran nun klemmen kann, weil wiederum dass device ggf. vom Protokoll abweicht und diese Wiederholung ggf. auch mehr als einmal braucht. Das würde Martin die Hinweise geben, was er ggf. korrigieren müßte.
Ggf. auch mir, wenn es devices gibt, die mehr als eine Wiederholung zwingend benötigen. Dann müßte die Wiederholung in die CUL Firmware rein, da Timeout-Timing über FHEM dann zu kritisch wird.

Hallo Ansgar,

sorry. Bin grad bissi im Stress...

Evtl. morgen, auf jeden Fall am Freitag.
Muss erst noch in Ruhe durchgehen was ich auf meinem Testsystem einspielen muss etc.

Und da ich mein Hauptsystem mit dem HM-CFG-USB wieder leer räumen will (damit nicht zu viel unbrauchbares Zeugs dazwischen kommt), will ich das mal lieber in Ruhe machen.

Soll ich das System mit dem HM-UART auch mitlauschen lassen?
Oder auch mal mit diesem Pairen und auch das Testsystem mitlauschen lassen??

Gruß, Joachim

[MadMax-FHEM]

Hallo Ansgar,

so habe mal getestet.
Hoffe es war richtig so und du kannst was damit anfangen...

Angehangen dann mal diverse Logs (für den Fall, dass sie zu groß zum Posten sind).
Ich hoffe die Namen sind sprechend genug.

Leider hatte ich beim ersten (manuellen) getConfig expert auf 1 stehen, daher habe ich noch ein getConfig nachgereicht mit expert 2.

Falls ich noch was tun kann bzw. was anderes einstellen (hätte sollen) einfach Bescheid geben.

Gruß, Joachim

P.S.: die Anpassungen/Änderungen etc. beim Testsystem sind im Asksin-Thread dokumentiert. Alle Systeme (hmusb, HMUART) auf aktuellem Stand, update kurz vor den Tests.

[noansi]

Hallo Joachim,

danke für das Logging.

Ich habe damit mal zufällig die automatische Wiederholung eines HMUART im Timing sehen können.  Zwei Wiederholungen und etwa 354ms bei fehlender Antwort vom device.

Das hat aber mit dem vorliegenden Display Problem nichts zu tun. Merkwürdige Wiederholungen sehe ich nicht. Bei dog_martin vermute ich mal Timing, also dass CUL für das device etwas zu früh sendet. Dann ist er wohl in die schon beschriebene Wiederholungsignoranzfalle geraten, so dass drücken der Taste nichts mehr gebracht hat.

Dein Log mit HMUART (hmId AFFE22 ?) ist etwas unglücklich gelaufen, da auch HMUSB (hmId AFFE11 ?) beim Pairing mitgemischt hat und einen Register read parallel auf das display mitgemacht hat.
War das nicht mal so gedacht, dass nur eine hmId im System sein sollte und über die VCCU das jeweilige IO-Device gewählt werden sollte?

Gruß, Ansgar.