Missing_Ack bei HM-LC-Sw1PBU-FM

[knxhm]

Hallo,

ich häng mich mal hier dazu, habe auch selbiges Problem bei 2 Aktoren dieses Typs. Den einen Aktor habe ich selbst gelötet und nachdem der sich so komisch verhielt habe ich auch noch einen fertigen gekauft aber - sie verhalten sich ähnlich. Ähnlich deswegen, weil es Variationen gibt, mal gehts, mal nicht, nach x mal pairen und reset, Strom weg und wieder dran, usw. Ich habe mal das pairing und einige Aktionen gesniffft und kommentiert was ich gemacht habe, ich hoffe das hilft um das Problem zu verstehen. FHEM hat update vom 30.9.2015


pairen
2015.09.30 19:42:37.984 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:42:37.991 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:04322E27 IDcnt:000E L:24 %
2015.09.30 19:42:50.090 0: HMLAN_Parse: HMLAN1 R:E33D579   stat:0000 t:04325D63 d:FF r:FFB4     m:00 8410 33D579 000000 06010000
2015.09.30 19:42:55.839 0: HMLAN_Parse: HMLAN1 R:E33D579   stat:0000 t:043273D9 d:FF r:FFAE     m:01 8400 33D579 000000 2300694C45513133313233313310010100
2015.09.30 19:43:00.874 0: HMLAN_Send:  HMLAN1 I:+33D579,00,00,00
2015.09.30 19:43:01.891 1: PERL WARNING: Use of uninitialized value in numeric comparison (<=>) at fhem.pl line 1771.
2015.09.30 19:43:01.936 0: HMLAN_Send:  HMLAN1 S:+33D579,00,00,00
2015.09.30 19:43:01.939 0: HMLAN_Send:  HMLAN1 S:S1F59AD7F stat:  00 t:00000000 d:01 r:1F59AD7F m:02 A001 26ED82 33D579 010E
2015.09.30 19:43:02.106 0: HMLAN_Parse: HMLAN1 R:E33D579   stat:0000 t:04328C53 d:FF r:FFBA     m:02 A410 33D579 26ED82 0601000040
2015.09.30 19:43:02.245 0: HMLAN_Parse: HMLAN1 R:R1F59AD7F stat:0001 t:04328C58 d:FF r:FFBA     m:02 A410 33D579 26ED82 0601000040
2015.09.30 19:43:02.987 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:43:02.994 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:04328FD7 IDcnt:000E L:24 %
2015.09.30 19:43:05.958 0: HMLAN_Send:  HMLAN1 S:+33D579,00,00,00
2015.09.30 19:43:05.965 0: HMLAN_Send:  HMLAN1 S:S1F59BD35 stat:  00 t:00000000 d:01 r:1F59BD35 m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:06.574 0: HMLAN_Parse: HMLAN1 R:R1F59BD35 stat:0008 t:00000000 d:FF r:7FFF     m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:06.577 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
2015.09.30 19:43:06.805 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:06.852 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:06.899 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:06.946 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:06.992 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.039 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.086 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.133 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.181 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.228 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.276 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.323 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.371 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:07.844 1: Error: HM_37DA47 has no TYPE
2015.09.30 19:43:10.868 0: HMLAN_Send:  HMLAN1 S:S1F59D063 stat:  00 t:00000000 d:01 r:1F59D063 m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:11.478 0: HMLAN_Parse: HMLAN1 R:R1F59D063 stat:0008 t:00000000 d:FF r:7FFF     m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:11.484 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
2015.09.30 19:43:15.729 0: HMLAN_Send:  HMLAN1 S:S1F59E360 stat:  00 t:00000000 d:01 r:1F59E360 m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:16.339 0: HMLAN_Parse: HMLAN1 R:R1F59E360 stat:0008 t:00000000 d:FF r:7FFF     m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:16.341 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
2015.09.30 19:43:20.126 0: HMLAN_Send:  HMLAN1 S:S1F59F48D stat:  00 t:00000000 d:01 r:1F59F48D m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:20.736 0: HMLAN_Parse: HMLAN1 R:R1F59F48D stat:0008 t:00000000 d:FF r:7FFF     m:03 A001 26ED82 33D579 00040000000000
2015.09.30 19:43:20.739 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
2015.09.30 19:43:27.990 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:43:27.997 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:0432F186 IDcnt:000E L:24 %
2015.09.30 19:43:53.014 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:43:53.021 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:0433534A IDcnt:000E L:24 %
2015.09.30 19:43:55.017 0: HMLAN_Parse: HMLAN1 R:E33D579   stat:0000 t:04335B0C d:FF r:FFB5     m:04 8410 33D579 000000 0601C800
mit lokalem taster eingeschaltet - ok
2015.09.30 19:44:18.025 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:44:18.032 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:0433B500 IDcnt:000E L:24 %
2015.09.30 19:44:25.044 0: HMLAN_Parse: HMLAN1 R:E33D579   stat:0000 t:0433D05C d:FF r:FFB9     m:06 8410 33D579 000000 06010000
mit lokalem taster aus - ok
2015.09.30 19:44:43.045 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:44:43.052 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:043416C0 IDcnt:000E L:24 %
2015.09.30 19:44:45.695 0: HMLAN_Send:  HMLAN1 S:+33D579,00,00,00
2015.09.30 19:44:45.698 0: HMLAN_Send:  HMLAN1 S:S1F5B42CE stat:  00 t:00000000 d:01 r:1F5B42CE m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:45.701 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:44:45.731 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:04342137 IDcnt:000E L:25 %
2015.09.30 19:44:46.307 0: HMLAN_Parse: HMLAN1 R:R1F5B42CE stat:0008 t:00000000 d:FF r:7FFF     m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:46.310 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
2015.09.30 19:44:47.636 0: HMLAN_Send:  HMLAN1 S:S1F5B4A63 stat:  00 t:00000000 d:01 r:1F5B4A63 m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:48.246 0: HMLAN_Parse: HMLAN1 R:R1F5B4A63 stat:0008 t:00000000 d:FF r:7FFF     m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:48.248 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
toggel vom web interface geht nicht
2015.09.30 19:44:51.927 0: HMLAN_Send:  HMLAN1 S:S1F5B5B26 stat:  00 t:00000000 d:01 r:1F5B5B26 m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:52.537 0: HMLAN_Parse: HMLAN1 R:R1F5B5B26 stat:0008 t:00000000 d:FF r:7FFF     m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:52.540 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
2015.09.30 19:44:56.642 0: HMLAN_Send:  HMLAN1 S:S1F5B6D91 stat:  00 t:00000000 d:01 r:1F5B6D91 m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:57.252 0: HMLAN_Parse: HMLAN1 R:R1F5B6D91 stat:0008 t:00000000 d:FF r:7FFF     m:07 A011 26ED82 33D579 0201C80000
2015.09.30 19:44:57.255 0: HMLAN_Parse: HMLAN1 no ACK from 33D579
2015.09.30 19:45:10.704 0: HMLAN_Send:  HMLAN1 I:K
2015.09.30 19:45:10.711 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:LEQ0102312 d:26ED82 O:26ED82 t:043482D0 IDcnt:000E L:25 %
jetzt hängt er auf missing ACK

[baumeister]

Hallo,

ja, habe config=anlernen status am device aktiviert. Ich habe es nun auch mal so weit getrieben, dass ich das Device an komplett aus fhem gelöscht habe, dann angelernt und alles in fhem gespeichert habe. Dazu passt der letzte Auszug aus dem Logfile. Das Device sendet wohl rein gar nichts mehr.

Ich habe gesehen, dass es ein Firmware Update zu diesem device gibt. Macht es Sinn da zu probieren, oder würde es fehlschlagen, da nicht gepaired?

[baumeister]

Hallo,

das Problem scheint ja bei weiteren HM-LC-Sw1PBU-FM aufzutreten. Bei mir ist es auch nach mehrtägiem Probieren nicht möglich mehr Debug Meldungen im Log zu erhalten. Das Device scheint einfach nicht zu antworten. Es lässt sicht nicht mehr mit fhem pairen. Hatr jemend noch eine weitere Idee, alle hier beschriebenen Tips waren leider erfolglos. Danke.

[frank]

irgendwas musst du doch falsch machen, denn:

wenn du das device löscht und es durch anlernen in fhem neu angelegt wird, muss fhem auch eine message empfangen haben. also, warum ist diese anlernmessage nicht in deinem log zu finden?

[baumeister]

Hallo,

so ich habe es nun noch einmal gemäß Anleitung gemacht:
Logging auf
attr global verbose 1
attr global mseclog 1
attr CUL_0 verbose 4
reload config
Device angelernt, folgender Inhalt im Logfile:

2015.10.04 11:44:40.845 4: CUL_Parse: CUL_0 A 1A 01 8400 1B732F 000000 2100694A455130313030373135100101002B -52.5
2015.10.04 11:44:40.849 1: in UNDEFINED
2015.10.04 11:44:40.850 1: in UNDEFINED
2015.10.04 11:44:40.875 1: in UNDEFINED
2015.10.04 11:44:40.875 1: in DEFINED
2015.10.04 11:44:40.875 1: in DEFINED
2015.10.04 11:44:40.876 1: in SAVE
2015.10.04 11:44:40.876 1: in UNDEFINED
2015.10.04 11:44:40.876 1: in DEFINED
2015.10.04 11:44:40.876 1: in DEFINED
2015.10.04 11:44:40.876 1: in SAVE
2015.10.04 11:44:40.876 1: in UNDEFINED
2015.10.04 11:44:40.876 1: in DEFINED
2015.10.04 11:44:40.876 1: in DEFINED
2015.10.04 11:44:40.876 1: in SAVE
2015.10.04 11:44:40.876 1: in UNDEFINED
2015.10.04 11:44:40.876 1: in DEFINED
2015.10.04 11:44:40.876 1: in DEFINED
2015.10.04 11:44:40.876 1: in SAVE
2015.10.04 11:44:40.878 1: in UNDEFINED
2015.10.04 11:44:40.878 1: in DEFINED
2015.10.04 11:44:40.878 1: in DEFINED
2015.10.04 11:44:40.878 1: in SAVE
2015.10.04 11:44:40.878 1: in UNDEFINED
2015.10.04 11:44:40.878 1: in DEFINED
2015.10.04 11:44:40.878 1: in DEFINED
2015.10.04 11:44:40.878 1: in SAVE
2015.10.04 11:44:40.878 1: in UNDEFINED
2015.10.04 11:44:40.878 1: in DEFINED
2015.10.04 11:44:40.878 1: in DEFINED
2015.10.04 11:44:40.878 1: in SAVE
2015.10.04 11:44:40.970 4: CUL_send:  CUL_0As 10 02 A001 F11234 1B732F 00050000000000
2015.10.04 11:44:44.619 4: CUL_send:  CUL_0As 10 02 A001 F11234 1B732F 00050000000000
2015.10.04 11:44:49.888 4: CUL_send:  CUL_0As 10 02 A001 F11234 1B732F 00050000000000
2015.10.04 11:44:54.521 4: CUL_send:  CUL_0As 10 02 A001 F11234 1B732F 00050000000000
2015.10.04 11:45:32.273 4: CUL_Parse: CUL_0 A 0E DC 8202 1F99EE 1F9371 010100002CC8 -102
2015.10.04 11:46:12.976 4: CUL_Parse: CUL_0 A 0C 7B 8670 29DABA 000000 008E6402 -73

Das Device ist dann nach config save gespeichert.
Die letzten beiden Zeilen stammen wohl eher schon von anderen Devices. Soll ich irgendwas am Vorgehen, Logging ändern? Danke

[frank]

Code Auswählen Erweitern

2015.10.04 11:44:40.845 4: CUL_Parse: CUL_0 A 1A 01 8400 1B732F 000000 2100694A455130313030373135100101002B -52.5
dein device kann also funken und fhem empfängt es. ist doch schon mal ein anfang.  hast du uns bisher verschwiegen.
allerdings antwortet es nicht auf messages von fhem.
ich denke es wäre am besten, du nutzt die timing optimierte fw für den cul. siehe hier: http://forum.fhem.de/index.php/topic,31421.0.html.

völlig unklar sind mir die meldungen zwischen den messages (habe ich noch nie gesehen):

Code Auswählen Erweitern

2015.10.04 11:44:40.875 1: in UNDEFINED
2015.10.04 11:44:40.875 1: in DEFINED
2015.10.04 11:44:40.875 1: in DEFINED
2015.10.04 11:44:40.876 1: in SAVE
2015.10.04 11:44:40.876 1: in UNDEFINED
2015.10.04 11:44:40.876 1: in DEFINED

reload config

es macht den eindruck, dass du die fhem.cfg bearbeitest. vielleich kommt es daher. das solltest du erst einmal vermeiden und über das webif arbeiten. ausserdem mal einen restart durchführen.

[baumeister]

Halllo,

Danke für den Tip mit der anderen CUL Firmware. Allerdings scheint mir diese noch in einem Teststadium zu sein, so dass is es auf meinem produktiven System lieber nicht einsetzen werden. Dafür hängt mitllerweile zu viel Automation schon im fhem.

ja ich mache viel über edit.config. Allerdings kommischerweise beim anlernen von Devices nie. Abe es aber alles noch einmal bewusst über die Eingabe gemacht und auch meinen fhem noch einmal sauber neu gestartet. Leider immer das selbe Spiel. Das Device will nicht pairen

Hilft hier eventuell der schon angesprochenee Firmware Update des Devices oder ist das ohne erfolgreiches Pairen nicht möglich? Danke

[frank]

Danke für den Tip mit der anderen CUL Firmware. Allerdings scheint mir diese noch in einem Teststadium zu sein, so dass is es auf meinem produktiven System lieber nicht einsetzen werden. Dafür hängt mitllerweile zu viel Automation schon im fhem.

du bist lustig. 
ich denke dein "stabiles produktivsystem" hat probleme.
wenn dir dieser punkt so wichtig ist, verstehe ich nicht, warum du überhaupt einen cul benutzt und den dann noch ohne timing optimierung. seltsam.

[baumeister]

Hallo,

wer nicht wagt, der nicht gewinnt. Nein Scherz beiseite. Mein fhem mit Cul läuft nun seit gut 3 Jahren ohne irgendwelche Zicken. Für kleiner Baustellen habe ich eine VM mit einem fhem oder halt ohne Cul.

Mir war das Projekt vorher nicht bekannt, auch nicht die Notwendigkeit bei HM Devices timeings zu optimieren. Was bringen diese Optimierungen und welchen Zusammenhang siehst du mit der aktuellen Unmöglichkeit dieses Device zu pairen? Danke.

[martinp876]

Hm device benötigen eine Antwort in einem 120ms Korridor.
Diemio fw ist eigentlich gut und schnell. Das Problem ist die Schnittstelle zwischen io und fhem.... Incl LAN, USB, und nicht zu vergessen OS des host.
Fhem könnte die diferenznerrechnen und ausgleichen, wenn das io infos schickt. Klappt prima.....
Wenn man im system keine delays hat, mag es so gehen. Ein timing Ausgleich ist ohne timestamps nicht machbar

[baumeister]

Danke für die Info.

Mal anders gefragt, kann es eventuell auch daran liegen, dass dieses Device zu nah an meiner Antenne verbaut ist? Es ist das einzige HM Device welches in einem Umkreis von weniger als 2 Meter verbaut wurde. Danke

[martinp876]

Moeglich. Einfach testen

[baumeister]

Hallo,

habe versucht das device mit der neuen Firmware zu bespielen. Das war offensichtlich leider nicht so erfolgreich. Mit der "fhem-Methode" passierte scheinbar gar nichts:

2015.10.10 15:30:18 2: CUL_HM fwUpdate started for WC_EG_Lampe
2015.10.10 15:30:18 3: CUL_HM set WC_EG_Lampe fwUpdate /opt/fhem/FHEM/firmware/HM-LC-Sw1PBU-FM_update_V2_8_2_150713.eq3 30
2015.10.10 15:30:48 2: CUL_HM fwUpdate WC_EG_Lampe end. IO-speed: normal
2015.10.10 15:31:10 3: CUL_HM set WC_EG_Lampe getConfig

Wird nach wie vor die alte Version angezeigt. Habe dann die "Linux-Methode" probiert. Hier bin ich nicht weiter gekommen, als das das Flash Tool auf Antwort vom Device gewartet hat. Das habe ich dann nach 15 Minuten abgebrochen. Ich habe irgendwie das Gefühl, dass das Device gar nicht mehr aus die Seriennummer reagiert. Ist so was möglich? Danke

[baumeister]

Hier dazu der Konsolen Output

HomeMatic OTA flasher version 0.101-git

Reading firmware from ../HM-LC-Sw1PBU-FM_update_V2_8_2_150713.eq3...
Firmware with 256 blocks successfully read.
Opening culfw-device at path /dev/ttyACM0 with speed 38400
Requesting firmware version
culfw-device firmware version: 1.65
Entering 10k-mode
Waiting for device with serial XXX

Das endet dann nicht erfolgreich.

[martinp876]

ich nutze nur fhem.
wenn du einen update startest versucht FHEM das Device aufzuwecken. Das geht schief, wenn es schon gelöscht ist.
Du musst dann FUP am Device starten (irgendwelche tasten, ich meine "config") dann wird fhem reagieren.

bei fwUpdate kannst du eine Zeit einstellen, wie lange FHEM wartet - auf das Config deines Device.