Error in CUL_MAX_SendQueueHandler: CUL SCC1 did not answer request for current

Begonnen von QuesT, 30 Oktober 2014, 21:34:58

Vorheriges Thema - Nächstes Thema

gero

Zitat von: stgeran am 14 November 2014, 19:04:17
Das Problem
PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
gibt es aber auch noch. Hoffentlich haben die beiden nichts miteinander zu tun.
Ich kenne den MaxScanner nicht wirklich. Aber wegen des "No answer" in einer credit10ms Variable sieht es mir ganz stark nach einem Folgefehler vom Parsingproblem aus.
Ich habe großen Respekt vor allen Entwicklern von fhem. Aber ein großes Problem ist das fehlende einheitliche Konzept Fehlerwerte und Meldungen aus Funktionen und Modulen zurückzugeben.

Gruß,
Gero

Odroid C1 - CULV3-868, JeeLink
16 x TX 29 DTH
MAX!: 15x Heizkörperthermostat+, 2x Wandthermostat, 14x Fenserkontakt, 1x Ecotaster
FS20 S4A, FS20IRF, BSB-Heizungssteuerung über Atmega2560
Z-Wave: ZME_UZB1, Fibaro Wall Plug + Motion Sensor

pklaus

Zitat von: pklaus am 14 November 2014, 13:23:11
Danke! Mit der Version scheint es nun erst einmal wieder zu funktionieren. (Ob für mehr als 24 Stunden, wird sich zeigen – ich hoffe es!)

Nachdem ich die alte Version von 00_CUL.pm wiederhergestellt habe funktioniert die Heizungssteuerung jetzt wieder zuverlässig. Ich habe aber dennoch erneut einen Fehler im Log gefunden, von dem sich FHEM aber wohl von selbst wieder erholt hat:

2014.11.14 21:54:30 3: MAX MAX_0dcce1: MaxScanRun.753 <<set MAX_0dcce1 desiredTemperature auto 18.5>>
2014.11.14 21:56:13 1: CUL_MAX_Parse: len mismatch
2014.11.14 21:56:16 1: /dev/cul868 disconnected, waiting to reappear (cul868)
2014.11.14 21:56:16 1: Error in CUL_MAX_SendQueueHandler: CUL cul868 did not answer request for current credits. Waiting 5 seconds.
2014.11.14 21:56:16 3: MAX MAX_0d284b: MaxScanRun.753 <<set MAX_0d284b desiredTemperature auto 18.0>>
2014.11.14 21:56:16 3: Setting cul868 baudrate to 9600
2014.11.14 21:56:16 1: /dev/cul868 reappeared (cul868)
2014.11.14 21:56:16 3: cul868: Possible commands: BbCFiAZEGMKUYRTVWXefmltux
2014.11.14 21:57:39 3: MAX MAX_0daaae: MaxScanRun.753 <<set MAX_0daaae desiredTemperature auto 19.0>>

gero

Zitat von: pklaus am 14 November 2014, 23:49:16
Nachdem ich die alte Version von 00_CUL.pm wiederhergestellt habe funktioniert die Heizungssteuerung jetzt wieder zuverlässig. Ich habe aber dennoch erneut einen Fehler im Log gefunden, von dem sich FHEM aber wohl von selbst wieder erholt hat:

2014.11.14 21:54:30 3: MAX MAX_0dcce1: MaxScanRun.753 <<set MAX_0dcce1 desiredTemperature auto 18.5>>
2014.11.14 21:56:13 1: CUL_MAX_Parse: len mismatch
2014.11.14 21:56:16 1: /dev/cul868 disconnected, waiting to reappear (cul868)
2014.11.14 21:56:16 1: Error in CUL_MAX_SendQueueHandler: CUL cul868 did not answer request for current credits. Waiting 5 seconds.
2014.11.14 21:56:16 3: MAX MAX_0d284b: MaxScanRun.753 <<set MAX_0d284b desiredTemperature auto 18.0>>
2014.11.14 21:56:16 3: Setting cul868 baudrate to 9600
2014.11.14 21:56:16 1: /dev/cul868 reappeared (cul868)
2014.11.14 21:56:16 3: cul868: Possible commands: BbCFiAZEGMKUYRTVWXefmltux
2014.11.14 21:57:39 3: MAX MAX_0daaae: MaxScanRun.753 <<set MAX_0daaae desiredTemperature auto 19.0>>


Der Parse-Fehler ist schon ewig vorhanden und wird durch den Rückschritt auf die letzte 00_CUL.pm Version nicht behoben.
Lediglich das Reappear vom CUL funktioniert jetzt wieder.

Es sind zwei Fehler zu beheben:
1. Mit der aktuellen Version von 00_CUL.pm funktioniert das Reappier nicht mehr.
2. Die Funktion CUL_ReadAnswer segmentiert empfangene Nachrichten nicht richtig und erzeugt dadurch unnötigerweise das Disconnect.

Laßt uns darauf warten, dass Rudolf König hier nochmal reinschaut und seinen Kommentar dazu abgibt.

Gruß,
Gero

Odroid C1 - CULV3-868, JeeLink
16 x TX 29 DTH
MAX!: 15x Heizkörperthermostat+, 2x Wandthermostat, 14x Fenserkontakt, 1x Ecotaster
FS20 S4A, FS20IRF, BSB-Heizungssteuerung über Atmega2560
Z-Wave: ZME_UZB1, Fibaro Wall Plug + Motion Sensor

stgeran

Ich habe auch die "alte" Verion. Jetzt kommt öfter
CUL_MAX_Parse: Got unhandled message type 4E
2014.11.14 23:50:12 2: CUL_MAX_Parse: Got unhandled message type F7
2014.11.14 23:50:12 2: CUL_MAX_Parse: Got unhandled message type F7
FHEM auf Raspberry
CSM 866MHz für EM1010 mit Strom und Gaszähler
CUL 866MHz für MAX! Radiator Thermostat 
CUL 433MHz für Innen und Aussen Temp
HMLAN für HM-LC-Sw1-PI-2

rudolfkoenig

Es ist eine lange Verkettung von Bugs & Zufaellen.

- CUL_ReadAnswer1: falls bei der Antwort auf die "credit10ms" Frage im Puffer noch andere Daten waren (in diesem Fall eine MAX-Nachricht, vermutlich weil FHEM wg. irgendwelche Verzoegerungen diese Daten noch nicht abgeholt hat), dann wurden diese _zusammen_ mit der credit10ms Antwort zum Analysieren freigegeben (deswegen die "len mismatch" Fehlermeldung).
Das habe ich jetzt gefixt und eingecheckt.

- CUL_ReadAnswer2: da die eigentliche Antwort an falsche Stelle geschickt ist, wartet diese Routine vergeblich die weiteren 3 Sekunden auf die Antwort, und schliesst danach die USB-Verbindung via DevIo_Disconnected (XXX disconnected, waiting to reappear). Welche Probleme das Schliessen loesen soll, weiss ich nicht, allerdings traue ich das nicht zu aendern. CUL_Get schliesst die Verbindung auch noch zusaetzlich im Fehlerfall.

- 00_CUL.pm: die Umstellung am 2014-10-12 auf readingsSingleUpdate sorgt dafuer, das die zwischenzeitlich auf "disconnected" gesetzte Status des CULs auf "Initialized" zurueckgesetzt wird, was wiederum das automatische "reappeared" verhindert.
Das habe ich jetzt gefixt und eingecheckt.

- Die credit10ms Abfrage vor jedem Senden halte ich fuer problematisch, weil das von CUL_MAX_Parse aufgerufene CUL_Get die CUL_MAX_Parse nochmal aufgeruft, falls vor dem Antwort auf die Daten MAX-Nachrichten sind. Weiterhin ist diese Abfrage inkompatibel mit FHEM2FHEM:RAW. Ich wuerde stattdessen diese Zaehlung im Modul selbst realisieren. Das Modul sollte von Log auf Log3 (bzw. von loglevel auf verbose) umgestellt werden.

-> Nach einem update (ab morgen) sollte das Problem verschwunden sein.

SirUli


Palm_Maniac

Auch von mir ein Herzliches Dankeschön an rudolfkoenig. :) Du machst uns MAX User damit sehr Glücklich. :)

gero

Zitat von: rudolfkoenig am 15 November 2014, 14:12:24
Es ist eine lange Verkettung von Bugs & Zufaellen.

- CUL_ReadAnswer1: falls bei der Antwort auf die "credit10ms" Frage im Puffer noch andere Daten waren (in diesem Fall eine MAX-Nachricht, vermutlich weil FHEM wg. irgendwelche Verzoegerungen diese Daten noch nicht abgeholt hat), dann wurden diese _zusammen_ mit der credit10ms Antwort zum Analysieren freigegeben (deswegen die "len mismatch" Fehlermeldung).
Das habe ich jetzt gefixt und eingecheckt.

- CUL_ReadAnswer2: da die eigentliche Antwort an falsche Stelle geschickt ist, wartet diese Routine vergeblich die weiteren 3 Sekunden auf die Antwort, und schliesst danach die USB-Verbindung via DevIo_Disconnected (XXX disconnected, waiting to reappear). Welche Probleme das Schliessen loesen soll, weiss ich nicht, allerdings traue ich das nicht zu aendern. CUL_Get schliesst die Verbindung auch noch zusaetzlich im Fehlerfall.

- 00_CUL.pm: die Umstellung am 2014-10-12 auf readingsSingleUpdate sorgt dafuer, das die zwischenzeitlich auf "disconnected" gesetzte Status des CULs auf "Initialized" zurueckgesetzt wird, was wiederum das automatische "reappeared" verhindert.
Das habe ich jetzt gefixt und eingecheckt.

- Die credit10ms Abfrage vor jedem Senden halte ich fuer problematisch, weil das von CUL_MAX_Parse aufgerufene CUL_Get die CUL_MAX_Parse nochmal aufgeruft, falls vor dem Antwort auf die Daten MAX-Nachrichten sind. Weiterhin ist diese Abfrage inkompatibel mit FHEM2FHEM:RAW. Ich wuerde stattdessen diese Zaehlung im Modul selbst realisieren. Das Modul sollte von Log auf Log3 (bzw. von loglevel auf verbose) umgestellt werden.

-> Nach einem update (ab morgen) sollte das Problem verschwunden sein.

Danke! Ich bin gespannt, wie deine Änderungen genau aussehen.

Wenn du Zeit hast, kannst du auch nochmal in diesen Thread sehen:
http://forum.fhem.de/index.php/topic,25745.0.html
Es gibt auch in der CUL-Firmware bzgl. MAX noch einen kleinen BUG.

Gruß,
Gero

Odroid C1 - CULV3-868, JeeLink
16 x TX 29 DTH
MAX!: 15x Heizkörperthermostat+, 2x Wandthermostat, 14x Fenserkontakt, 1x Ecotaster
FS20 S4A, FS20IRF, BSB-Heizungssteuerung über Atmega2560
Z-Wave: ZME_UZB1, Fibaro Wall Plug + Motion Sensor

rudolfkoenig

ZitatDanke! Ich bin gespannt, wie deine Änderungen genau aussehen.
Dann schau ins SVN. Ich meine Minimalinvasiv.

Wenn du Zeit hast, kannst du auch nochmal in diesen Thread sehen:
Habs gesehen, fuehl mich aber nicht zustaendig, da es nicht von mir ist, ausserdem kann ich es nicht testen.
Wenn Matthias keine Zeit hat, dann muesste jemand anderes (Du?) die Pflege uebernehmen.

gero

Zitat von: rudolfkoenig am 15 November 2014, 21:02:42
Dann schau ins SVN. Ich meine Minimalinvasiv.
Habe ich gerade gemacht. Die Änderung sollte das aktuelle Problem beheben.
Aber sauberer wäre es doch, wenn man in CUL_ReadAnswer auch noch $hash->{PARTIAL} mit berücksichtigen würde, oder sehe ich das falsch? Ebenso kann man nur hoffen, dass in CUL_ReadAnswer die Antwort auf das letzte Kommando komplett vom CUL gelesen wird. Falls das letzte Telegram im Buffer unvollständig ist, müßte evtl. nochmal gelesen werden. Ob und wie hoch die Wahrscheinlichkeit, für ein nicht komplettes Lesen ist, wage ich gerade nicht zu beurteilen. Schöner wäre es natürlich, wenn man auf CUL_ReadAnswer komplett verzichten könnte. Aber es ist manchmal von der Softwarearchitektur einfacher, wenn man einen blocking call an Stellen realisieren kann, an denen man eigentlich asynchron arbeiten müßte.
Bitte sieh meine Äußerungen nicht als böse Kritik. Ich will nur konstruktiv weiterhelfen, soweit es mir möglich ist.

Zitat von: rudolfkoenig am 15 November 2014, 21:02:42
Wenn du Zeit hast, kannst du auch nochmal in diesen Thread sehen:
Habs gesehen, fuehl mich aber nicht zustaendig, da es nicht von mir ist, ausserdem kann ich es nicht testen.
Wenn Matthias keine Zeit hat, dann muesste jemand anderes (Du?) die Pflege uebernehmen.
Soweit es in meinen Möglichkeiten liegt (vor allem zeitlich), möchte ich die fhem Entwicklung natürlich unterstützen.
Sprichst du von 14_CUL_MAX.pm oder vom rf_moritz in der CUL Firmware?

Gruß,
Gero
Odroid C1 - CULV3-868, JeeLink
16 x TX 29 DTH
MAX!: 15x Heizkörperthermostat+, 2x Wandthermostat, 14x Fenserkontakt, 1x Ecotaster
FS20 S4A, FS20IRF, BSB-Heizungssteuerung über Atmega2560
Z-Wave: ZME_UZB1, Fibaro Wall Plug + Motion Sensor

hyper2910

Cubietruck mit FHEM, CUL V3 443MHz, 2 x CULV3 868MHz, Milights, Max Heizungssteuerung, Homematic, IT,

rudolfkoenig

@gero: ich meinte beides.
Aber wir sollten noch eine Woche auf Matthias warten, drei Wochen Urlaub waeren nichts ungewoehnliches.

Matthias Gehre

So, bin wieder da :-)

Die Log3 Umstellung kann ich in der nächsten Woche machen.

Zu:
ZitatDie credit10ms Abfrage vor jedem Senden halte ich fuer problematisch, weil das von CUL_MAX_Parse aufgerufene CUL_Get die CUL_MAX_Parse nochmal aufgeruft, falls vor dem Antwort auf die Daten MAX-Nachrichten sind. Weiterhin ist diese Abfrage inkompatibel mit FHEM2FHEM:RAW. Ich wuerde stattdessen diese Zaehlung im Modul selbst realisieren. Das Modul sollte von Log auf Log3 (bzw. von loglevel auf verbose) umgestellt werden.
Das muss ich mir noch einmal anschauen, Ich glaube das ursprüngliche Problem war, dass das MAX Modul keine Rückmeldung hatte, falls der CUL die Pakete wg fehlenden Credits nicht sendet.
Ich schau mir das nochmal an.

deune

Hallo Zusammen,

Heute Morgen ein update gemacht und ich bin guter Dinge das es nun stabiler läuft und die Rückmeldung von Matthias vertreibt jeglichen Kummer - Vielen lieben Dank allen Zusammen!

Holger

hyper2910

Cubietruck mit FHEM, CUL V3 443MHz, 2 x CULV3 868MHz, Milights, Max Heizungssteuerung, Homematic, IT,