[gelöst] HM-CC-RT-DN kein Pairing möglich mit Rawlogs und HM configCheck

Raven · 20 November 2014, 08:28:36

Seit Wochen kämpfe ich und wühle hier das Forum durch, aber ich konnte nichts finden. Daher unten die Rawlogs für den 1. Problemfall angehängt. Evtl. seht ihr was.

Bei Aufruf von HM configCheck erhalte ich diese Meldung (Warum?):
templist mismatch
CUL_HM_HM_CC_RT_DN_28BB3B_Clima: file: ./tempList.cfg for CUL_HM_HM_CC_RT_DN_28BB3B_Clima does not exist

Teilw. fehlt die SerienNummer im Log:
2014.11.20 07:07:36 2: CUL_HM Unknown device CUL_HM_HM_CC_RT_DN_28BB3B is now defined
2014.11.20 07:07:36 2: autocreate: define CUL_HM_HM_CC_RT_DN_28BB3B CUL_HM 28BB3B
2014.11.20 07:07:36 2: autocreate: define FileLog_CUL_HM_HM_CC_RT_DN_28BB3B FileLog ./log/CUL_HM_HM_CC_RT_DN_28BB3B-%Y.log CUL_HM_HM_CC_RT_DN_28BB3B
2014.11.20 07:07:48 3: Device CUL_HM_HM_CC_RT_DN_28BB3B added to ActionDetector with 000:10 time
2014.11.20 07:07:48 3: CUL_HM pair: CUL_HM_HM_CC_RT_DN_28BB3B thermostat, model HM-CC-RT-DN serialNr
2014.11.20 07:07:48 3: CUL_HM set CUL_HM_HM_CC_RT_DN_28BB3B getConfig
2014.11.20 07:08:17 3: Device CUL_HM_HM_CC_RT_DN_28BB3B added to ActionDetector with 000:10 time
2014.11.20 07:10:08 3: CUL_HM set CUL_HM_HM_CC_RT_DN_28BB3B getConfig
2014.11.20 07:11:30 3: Device CUL_HM_HM_CC_RT_DN_28BB3B added to ActionDetector with 000:10 time
2014.11.20 07:12:00 3: Device CUL_HM_HM_CC_RT_DN_28BB3B added to ActionDetector with 000:10 time
2014.11.20 07:15:27 3: CUL_HM set CUL_HM_HM_CC_RT_DN_28BB3B getConfig
2014.11.20 07:21:57 3: CUL_HM set CUL_HM_HM_CC_RT_DN_28BB3B clear msgEvents
2014.11.20 07:22:13 3: Device CUL_HM_HM_CC_RT_DN_28BB3B added to ActionDetector with 000:10 time
2014.11.20 07:22:13 3: CUL_HM pair: CUL_HM_HM_CC_RT_DN_28BB3B thermostat, model HM-CC-RT-DN serialNr LEQ040XXXXX

set CUL_HM_HM_CC_RT_DN_28BB3B clear msgEvents
set HMLAN1 hmPairForSec 120 - nAC erhalten
2014.11.20 07:56:38.117 0: HMLAN_Parse: HMLAN1 R:E28BB3B stat:0000 t:4BC97453 d:FF r:FFBA m:01 8400 28BB3B 000000 1300954C4551303430323239355900FFFF
2014.11.20 07:56:38.142 0: HMLAN_Send: HMLAN1 I:+28BB3B,02,01,00
2014.11.20 07:56:38.156 0: HMLAN_Send: HMLAN1 S:SCBFD0A54 stat: 00 t:00000000 d:01 r:CBFD0A54 m:7F A001 1E9D86 28BB3B 00050000000000
2014.11.20 07:57:01.877 0: HMLAN_Send: HMLAN1 I:K

set CUL_HM_HM_CC_RT_DN_28BB3B clear msgEvents
set HMLAN1 hmPairForSec 120 - nAC erhalten
2014.11.20 08:01:19.444 0: HMLAN_Parse: HMLAN1 R:E28BB3B stat:0000 t:4BCDB77E d:FF r:FFBA m:01 8400 28BB3B 000000 1300954C4551303430323239355900FFFF
2014.11.20 08:01:26.320 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0707399 d:1E9D86 O:1E9D86 t:4BCDCA69 IDcnt:0036
2014.11.20 08:01:31.371 0: HMLAN_Parse: HMLAN1 R:RCC015517 stat:0001 t:4BCDCB10 d:FF r:FFB8 m:83 8002 28BB3B 1E9D86 00
2014.11.20 08:01:31.376 0: HMLAN_Send: HMLAN1 S:SCC0183B8 stat: 00 t:00000000 d:01 r:CC0183B8 m:84 A001 1E9D86 28BB3B 00050000000000
2014.11.20 08:01:33.351 0: HMLAN_Parse: HMLAN1 R:RCC0183B8 stat:0008 t:00000000 d:FF r:7FFF m:84 A001 1E9D86 28BB3B 00050000000000
2014.11.20 08:01:33.352 0: HMLAN_Parse: HMLAN1 no ACK from 28BB3B

2014.11.20 08:08:13.420 0: HMLAN_Parse: HMLAN1 R:E28BB3B stat:0000 t:4BD40A7D d:FF r:FFB6 m:01 8400 28BB3B 000000 1300954C4551303430323239355900FFFF
2014.11.20 08:08:13.446 0: HMLAN_Send: HMLAN1 I:+28BB3B,02,01,00
2014.11.20 08:08:13.460 0: HMLAN_Send: HMLAN1 S:SCC07A65C stat: 00 t:00000000 d:01 r:CC07A65C m:85 A001 1E9D86 28BB3B 00050000000000
2014.11.20 08:08:36.658 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0707399 d:1E9D86 O:1E9D86 t:4BD40E14 IDcnt:0036
2014.11.20 08:08:37.785 0: HMLAN_Send: HMLAN1 I:K
2014.11.20 08:08:37.812 0: HMLAN_Parse: HMLAN1 R:RCC07A65C stat:0001 t:4BD41C93 d:FF r:FFC0 m:85 8002 28BB3B 1E9D86 00
2014.11.20 08:08:37.817 0: HMLAN_Send: HMLAN1 S:SCC080581 stat: 00 t:00000000 d:01 r:CC080581 m:86 A001 1E9D86 28BB3B 00050000000000
2014.11.20 08:08:44.659 0: HMLAN_Parse: HMLAN1 V:03C1 sNo:JEQ0707399 d:1E9D86 O:1E9D86 t:4BD47B02 IDcnt:0036

Danke voarb.

Status:
- Wiki "HomeMatic Devices pairen" gelesen und angewendet
- 8 RT-DN bereits seit 6 Monaten erfolgreich eingebunden
- der 1. Problemfall (FW: 1.3 ) war bereits mal erfolgreich eingebunden, mit Fensterkontakt gepairt (diesen auch gelöscht) und war umbenannt. Mehrfach nun die CFG-Files (sogar FEHM.save) nach Rückständen durchsucht und bereinigt.
- der 2. Problemfall ist nagelneu und hier klappt das Pairing auch nicht. Sprich hier sind also keine alte Namensrückstände in den CFG-Files, die evtl. stören könnten.
- verschiedene HMLAN-Abstände beim Pairing versucht (zw. 1,5 und 3m)
- neue Batterien verwendet
- hin und wieder erhalte ich nAC; aber nicht reproduzierbar (bspw. zu naher Kontakt beim Anlernversuch)
- FHEM-Update am 18.Nov.
- diese Threads bereits studiert (aber keine Lösungshinweise gefunden):
      HM-CC-RT-DN verweigert Pairing/Entpairing
         http://forum.fhem.de/index.php/topic,28410.msg212798.html#msg212798

      Mal wieder das Problem mit dem "pairen"
         http://forum.fhem.de/index.php/topic,27473.msg203656.html#msg203656

WolfgangV · 21 November 2014, 00:20:21

Hallo,

bei mir hat geholfen:

1. Alle Einträge der problematischen Geräte aus der fhem.cfg löschen (oder besser durch # auskommentieren)
2. save
3. shutdown restart
4. neu pairen.

Gruß

Wolfgang

Raven · 21 November 2014, 07:22:39

Danke Wolfgang. Das habe ich auch gemacht; leider erfolglos.

wkarl · 21 November 2014, 10:13:31

Hallo,

ist schon eine Weile her, dass ich meine DNs gepaired habe. Aber ich habe damals festgestellt, dass der erste pairing-Versuch mit NAK (am DN) quitiert wurde und das device unvollständig in fhem angelegt wurde. Die Lösung war dann nach dem ersten einen zweiten und falls nötig noch einen dritten Anlernschritt am DN auszulösen. Spätestens beim dritten kam dann ein ACK am DN und in fhem ist das device vollständig angelegt.
Seitdem laufen meine DNs hier klaglos.

ciao walter

WolfgangV · 21 November 2014, 14:32:38

Hallo,

achja, hatte ich vergessen:

die hm-cc-rt-dn mit Werksreset vor dem Pairingversuch zurücksetzen:
Batterien raus
alle drei Tasten halten
Batterien rein
warten, bis reset-Meldung auftaucht und wieder verschwindet.

Gruß

Wolfgang

Raven · 21 November 2014, 17:34:38

Danke Walter und Wolfgang für die Hilfe.

ich hab schon mehrere Anlernversuche "gleich" hintereinander durchgeführt (die MsgEvents jeweils zuvor gelöscht)
auch Batterien raus / 3-Tasten-Reset ergebnislos durchgeführt

Seit Wochen probiere ich immer wieder diese "Drecksdinger"

anzulernen, aber ohne Erfolg.

Ich hab von den problematischen Pairing-Versuchen bei umbenannten Devices gelesen, aber
1) ich habe alte "Namensrestbestände" im Config-File gelöscht
2) der neue brandneue Thermostat läßt sich auch nicht pairen.

Zwischenzeitlich habe ich wieder 2 neue andere Devices (Unterputz-Taster) ohne Probs gepairt.
Ist mir schleierhaft, warum ich solche Probs mit den Thermostaten habe.

WolfgangV · 21 November 2014, 19:07:56

Hallo,

weiß nicht, ob das auch was damit zu tun hat:

Ich bin con CUL auf HMlan umgezogen. Hatte vorher ähnliche Probleme: dauernd unvollständige Configfiles, vergebliche Pairingversuche.
Ich weiß nicht, wie die Erfahrungen anderer hierzu sind.

Gruß

Wolfgang

martinp876 · 22 November 2014, 16:37:31

das ist alles viel zu langsam.

set CUL_HM_HM_CC_RT_DN_28BB3B clear msgEvents
set HMLAN1 hmPairForSec 120 - nAC erhalten
07:56:38.117 Parse: HMLAN1 R:E28BB3B stat:0000 m:01 8400 28BB3B 000000 1300954C4551303430323239355900FFFF
07:56:38.142 Send: HMLAN1 I:+28BB3B,02,01,00
07:56:38.156 Send: HMLAN1 S:SCBFD0A54 stat: 00 m:7F A001 1E9D86 28BB3B 00050000000000
==> log abgeschnitten HMLAN antwortet hier immer noch einmal

set CUL_HM_HM_CC_RT_DN_28BB3B clear msgEvents
set HMLAN1 hmPairForSec 120 - nAC erhalten
08:01:19.444 Parse: HMLAN1 R:E28BB3B stat:0000 m:01 8400 28BB3B 000000 1300954C4551303430323239355900FFFF
08:01:31.371 Parse: HMLAN1 R:RCC015517 stat:0001 m:83 8002 28BB3B 1E9D86 00
08:01:31.376 Send: HMLAN1 S:SCC0183B8 stat: 00 m:84 A001 1E9D86 28BB3B 00050000000000
08:01:33.351 Parse: HMLAN1 R:RCC0183B8 stat:0008 m:84 A001 1E9D86 28BB3B 00050000000000
==> das device sendet um "19", dann eine Antwort 22!!!!! sec später. da ist schon lange alles vorbei

08:08:13.420 Parse: HMLAN1 R:E28BB3B stat:0000 m:01 8400 28BB3B 000000 1300954C4551303430323239355900FFFF
08:08:13.446 Send: HMLAN1 I:+28BB3B,02,01,00
08:08:13.460 Send: HMLAN1 S:SCC07A65C stat: 00 m:85 A001 1E9D86 28BB3B 00050000000000
08:08:37.812 Parse: HMLAN1 R:RCC07A65C stat:0001 m:85 8002 28BB3B 1E9D86 00
08:08:37.817 Send: HMLAN1 S:SCC080581 stat: 00 m:86 A001 1E9D86 28BB3B 00050000000000
===> das Kommando kommt pünktlich, die antwort 24!!!!!!sec später.

Dein sytem ist nicht langsam - es schläft ständig. Da hast du ein immenses Problem. Wer auch immer hier blockiert - finde ihn (apptime?)

Dann reden wir über CUL_HM.

Raven · 23 November 2014, 10:45:02

Danke Danke Danke.

Danke Wolfgang - Basierend auf Deinen Ausführungen wollte ich mit einer neuen FHEM-Basis-Konfiguration das Problem weiter eingrenzen.
Und Martin deckte "schonungslos" und dankeswerterweise mein Performanceproblem auf. Zwar hatte ich auch zuletzt die extrem langen Web-Antwortzeiten bemerkt, aber (leider) als gegeben hingenommen.
Das mein Performance-Problem mit dem Pairing in Verbindung steht, kam mir nicht in den Sinn, da ich vorgestern noch neue Aktoren anlernen konnte.
D.h. die Thermostate sind in dieser Hinsicht wohl sensibler gestrickt, als andere HM-Aktoren.

Auf jeden Fall hat mir der Performance-Hinweis nun die Sinne geschärft mehr auf die Performance zu achten.
Seit gestern abend, räume ich mit apptime und Perform-Monitor mein System auf und die Webantwortzeiten haben sich schon merklich verbessert.

Bei apptime muss ich überwiegend maxDly betrachten. Richtig?
Und hier sind die Kandidaten (habe diese zwecks Übersichtkeit hier gruppiert).
Bzghl. der HMLAN Aufrufe hab ich hier im Forum gesucht, aber keine weiteren Infos gefunden.
Hier weiß ich auch nicht, ob überhaupt Verbesserungspotential besteht.
Ein anderer Schwerpkt. bilden die HUE-Lampen. Hier müßte ich wohl schauen, ob es Maßnahmen gibt.
Frage mich, warum die at-Aufrufe so hohe maxDly aufweisen.

name function max count total average maxDly
tmr-at_Exec HASH(0x293f4c8) 12 63 134 2.13 59009 HASH(check)
tmr-at_Exec HASH(0x293f5b8) 2 63 118 1.87 59008 HASH(check2)
tmr-at_Exec HASH(0x2007d58) 82 42 1599 38.07 23609 HASH(heartbeat)

tmr-HMLAN_KeepAlive keepAlive:HMLAN1 12 1399 1793 1.28 40668 keepAlive:HMLAN1
tmr-HMLAN_UpdtMsgCnt UpdtMsg:HMLAN1 0 372 0 0.00 38533
tmr-HMLAN_KeepAliveCheck keepAliveCk:HMLAN1 11 1478 104 0.07 30565 keepAliveCk:HMLAN1
tmr-FW_closeOldClients 14 613 1968 3.21 20694
tmr-CUL_HM_ActCheck ActionDetector 3939 63 52983 841.00 20622 ActionDetector

tmr-HUEBridge_GetUpdate HASH(0x2af0a10) 101 125 8391 67.13 54402 HASH(bridge)
tmr-HUEDevice_GetUpdate HASH(0x2bfc4e0) 3751 611 27417 44.87 53502 HASH(Licht_Gaderobe)
tmr-HUEDevice_GetUpdate HASH(0x2bfc0a8) 40 611 11915 19.50 20718 HASH(Licht_WZ_Stehlampe)
tmr-HUEDevice_GetUpdate HASH(0x2b9c900) 1331 610 31646 51.88 20706 HASH(Licht_EZ_Stehlampe)
tmr-HUEDevice_GetUpdate HASH(0x2bf5ae0) 49 611 11833 19.37 20706 HASH(Licht_WZ)
tmr-HUEDevice_GetUpdate HASH(0x2c65e80) 4341 613 72003 117.46 20693 HASH(Licht_Treppe_Fenster)

justme1968 · 23 November 2014, 11:28:56

das problem bei den hue lampen ist das ich aktiv pollen muss um den aktuellen status zu bekommen. wie viele lampen hast du? wie hast du das polling itervall eingestellt?

ich habe schon eine version der hue module hier die das polling nonblocking macht und auch alle devices auf ein mal anfragen kann. das sollte weniger verzögerung verursachen.

gruß
andre

Raven · 23 November 2014, 11:40:39

Danke Andre.

Ich fall gerade vom Stuhl, hätte nicht gedacht, daß Du meinen dezenten Hue-Hinweis oben überhaupt mitbekommst.

- sind 5 Lampen
- polling ist 60 (hatte ich bisher nicht angepasst). In der Tat, könnte ich hochsetzen.
- sehr gut, Deinen Hue Thread verfolge ich, werde dann auf die neue Version achten.

Raven · 24 November 2014, 20:16:29

Gelöst! Aber ich verstehe es nicht wie das Pairing im Detail fkt.
Zunächst starte ich 'set HMLAN1 hmPairForSec 120' und 1 bis 2 Sek später drücke ich die Anlerntaste am Thermostat.
Dieser zählte (reproduzierbar) runter: 30-29-nACK.
Ja, mein FHEM lief / läuft langsam, dennoch bin ich verwundert, das nACK bereits innerhalb 1,5sec kommt.
Würde das nACK nach 28sec kommen, könnte ich das verstehen, daß dies mit der schlechten Performance zs.hängt.
Mit Hilfe von Perfom habe ich gesehen, daß dblog (MYSQL) evtl. die Ursache ist;
daher vorübergehend MYSQL deaktiviert und dann klappte auch das Anlernen.

Bin jetzt auf der Suche MYSQL zu optimieren.

Zitat2014.11.23 22:04:59 5: Cmd: >set HMLAN1 hmPairForSec 120<
2014.11.23 22:04:59 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem?room=CUL_HM
2014.11.23 22:05:00 4: /fhem?room=CUL_HM / RL:3410 / text/html; charset=UTF-8 / Content-Encoding: gzip

2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/style.css
2014.11.23 22:05:00 4: Connection accepted from FHEMWEB:192.168.178.182:60973
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60960 GET /fhem/pgm2/cordova-2.3.0.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/jscolor/jscolor.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60973 GET /fhem/js/webviewcontrol.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/jquery-ui.min.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60960 GET /fhem/pgm2/jquery.min.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/svg.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60973 GET /fhem/pgm2/dashboard.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/fhemweb_colorpicker.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60960 GET /fhem/pgm2/fhemweb.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60973 GET /fhem/pgm2/fhemweb_multiple.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/fhemweb_noArg.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60973 GET /fhem/pgm2/fhemweb_slider.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60960 GET /fhem/pgm2/fhemweb_readingsHistory.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/fhemweb_svg.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60973 GET /fhem/pgm2/fhemweb_textField.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/icons/favicon
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60960 GET /fhem/pgm2/fhemweb_time.js
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/defaultCommon.css
2014.11.23 22:05:00 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/pgm2/dashboard_style.css
2014.11.23 22:05:00 5: Triggering Heizung (1 changes)
2014.11.23 22:05:00 5: Notify loop for Heizung Temp-WarmWasser-Ist: 53.9
2014.11.23 22:05:00 5: DbLog: logging of Device: Heizung , Type: VCONTROL , Event: Temp-WarmWasser-Ist: 53.9 , Reading: Temp-WarmWasser-Ist , Value: 53.9 , Unit:
2014.11.23 22:05:01 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem/images/default/icoEverything.png
2014.11.23 22:05:01 4: HTTP FHEMWEB:192.168.178.182:60973 GET /fhem/images/default/off.png
2014.11.23 22:05:01 4: HTTP FHEMWEB:192.168.178.182:60960 GET /fhem/images/default/fhemicon.png
2014.11.23 22:05:02 4: HTTP FHEMWEB:192.168.178.182:60963 GET /fhem?XHR=1&inform=type=status;filter=room=CUL_HM&timestamp=1416776799008
2014.11.23 22:05:03 5: Triggering Heizung (1 changes)
2014.11.23 22:05:03 5: Notify loop for Heizung Temp-WarmWasser-Soll: 50
2014.11.23 22:05:03 5: DbLog: logging of Device: Heizung , Type: VCONTROL , Event: Temp-WarmWasser-Soll: 50 , Reading: Temp-WarmWasser-Soll , Value: 50 , Unit:
2014.11.23 22:05:06 5: HMLAN/RAW: /E28BB3B,0000,055A8BF8,FF,FFBD,01840028BB3B0000001300954C4551303430323239355900FFFF

2014.11.23 22:05:06 5: HMLAN_Parse: HMLAN1 R:E28BB3B stat:0000 t:055A8BF8 d:FF r:FFBD m:01 8400 28BB3B 000000 1300954C4551303430323239355900FFFF
2014.11.23 22:05:06 5: HMLAN1 dispatch A1A01840028BB3B0000001300954C4551303430323239355900FFFF::-67:HMLAN1
2014.11.23 22:05:06 3: Device CUL_HM_HM_CC_RT_DN_28BB3B added to ActionDetector with 000:10 time
2014.11.23 22:05:06 4: Device CUL_HM_HM_CC_RT_DN_28BB3B is alive
2014.11.23 22:05:06 3: CUL_HM pair: CUL_HM_HM_CC_RT_DN_28BB3B thermostat, model HM-CC-RT-DN serialNr LEQ0402295
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:1
2014.11.23 22:05:06 5: HMLAN_Send: HMLAN1 I:+28BB3B,02,01,00
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:2
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:3
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:4
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:5
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:6
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:7
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:8
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:9
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:10
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:11
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:12
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:13
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:14
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:15
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:16
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:17
2014.11.23 22:05:06 3: CUL_HM set CUL_HM_HM_CC_RT_DN_28BB3B getConfig
2014.11.23 22:05:06 5: HMLAN_Send: HMLAN1 S:SDE78E994 stat: 00 t:00000000 d:01 r:DE78E994 m:3E A001 1E9D86 28BB3B 00050000000000
2014.11.23 22:05:06 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_processing... pending:16
2014.11.23 22:05:06 5: Triggering CUL_HM_HM_CC_RT_DN_28BB3B (20 changes)
2014.11.23 22:05:06 5: Notify loop for CUL_HM_HM_CC_RT_DN_28BB3B D-firmware: 1.3
2014.11.23 22:05:06 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: D-firmware: 1.3 , Reading: D-firmware , Value: 1.3 , Unit:
2014.11.23 22:05:07 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: D-serialNr: LEQ0402295 , Reading: D-serialNr , Value: LEQ0402295 , Unit:
2014.11.23 22:05:08 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: Activity: alive , Reading: Activity , Value: alive , Unit:
2014.11.23 22:05:10 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:11 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:12 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:13 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:15 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:16 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:17 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:18 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:19 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:21 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:22 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:23 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:24 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:25 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:26 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:28 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:29 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:30 1: Perfmon: possible freeze starting at 22:05:07, delay is 23.462
2014.11.23 22:05:30 4: CUL_HM_Resend: CUL_HM_HM_CC_RT_DN_28BB3B nr 2
2014.11.23 22:05:30 5: Triggering CUL_HM_HM_CC_RT_DN_28BB3B (1 changes)
2014.11.23 22:05:30 5: Notify loop for CUL_HM_HM_CC_RT_DN_28BB3B CMDs_pending
2014.11.23 22:05:30 5: DbLog: logging of Device: CUL_HM_HM_CC_RT_DN_28BB3B , Type: CUL_HM , Event: CMDs_pending , Reading: state , Value: CMDs_pending , Unit:
2014.11.23 22:05:31 5: CUL_HM CUL_HM_HM_CC_RT_DN_28BB3B protEvent:CMDs_pending pending:17
2014.11.23 22:05:31 4: HMLAN_ack: timeout - clear queue

MarcelK · 25 November 2014, 00:12:18

Zitat von: Raven am 24 November 2014, 20:16:29
Gelöst! Aber ich verstehe es nicht wie das Pairing im Detail fkt.
Zunächst starte ich 'set HMLAN1 hmPairForSec 120' und 1 bis 2 Sek später drücke ich die Anlerntaste am Thermostat.
Dieser zählte (reproduzierbar) runter: 30-29-nACK.
Ja, mein FHEM lief / läuft langsam, dennoch bin ich verwundert, das nACK bereits innerhalb 1,5sec kommt.

Wieso wundert Dich das? Der RT will ne Antwort innerhalb von einer Sekunde (oder so). Wenn die nicht kommt ist es eben nACK. Ob Dein lahmendes FHEM danach nochmal 27 Sekunden braucht (wie im Log gesehen) oder zwei Tage ist dabei eher unerheblich

Raven · 25 November 2014, 07:34:28

Au Mann...hier war ich i.d.T. gedanklich völlig auf der falschen Spur.
Ich dachte, der Pairing-(Kommunikations)Prozess läuft (im schlimmsten Fall) über die gesamten 30sec.
Aber klar, der RT sendet bereits einmal bei 30 und erwartet dann bei 29 eine Rückmeldung, kommt diese nicht ist aus die Maus.

Vielen Dank für den Hinweis.