Autor Thema: Error in CUL_MAX_SendQueueHandler: CUL SCC1 did not answer request for current  (Gelesen 16692 mal)

Offline stgeran

  • Sr. Member
  • ****
  • Beiträge: 959
Diese Fehler sind immer noch da:
2014.11.06 04:45:52 3: MAX Hzg_WZ_RE: MaxScanRun.753 <<set Hzg_WZ_RE desiredTemperature auto 21.0>>
2014.11.06 04:45:52 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:45:52 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:46:26 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:46:26 1: PERL WARNING: Use of uninitialized value $credit10ms in string eq at ./FHEM/14_CUL_MAX.pm line 478.
2014.11.06 04:46:26 1: PERL WARNING: Use of uninitialized value $credit10ms in concatenation (.) or string at ./FHEM/14_CUL_MAX.pm line 485.
2014.11.06 04:46:26 3: MAX Hzg_Buero: MaxScanRun.753 <<set Hzg_Buero desiredTemperature  21.0>>
2014.11.06 04:46:26 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:46:26 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:49:29 1: 192.168.100.110:1000 disconnected, waiting to reappear (HMLAN1)
2014.11.06 04:49:29 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.11.06 04:49:30 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:49:30 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:49:30 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:50:29 1: 192.168.100.110:1000 reappeared (HMLAN1)
2014.11.06 04:50:29 1: HMLAN_Parse: HMLAN1 new condition init
2014.11.06 04:50:30 1: HMLAN_Parse: HMLAN1 new condition ok
2014.11.06 04:50:41 1: PERL WARNING: Argument "No answer" isn't numeric in addition (+) at ./FHEM/99_UtilsMaxScan.pm line 528.
2014.11.06 04:50:41 1: [color=red]PERL WARNING: Use of uninitialized value $credit10ms in string eq at ./FHEM/14_CUL_MAX.pm line 478.[/color]
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

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18557
Die Meldungen koennen nicht von einem aktuellen fhem.pl stammen.
Auch wenn es unwahrscheinlich ist, dass es in diesem Fall daran liegt, ist mir wichtig, dass alles aktuell ist.

Offline locutus

  • Sr. Member
  • ****
  • Beiträge: 812
  • No support over PM! Please use the thread ...
Die Meldungen treten seit dem gestrigen Update wieder auf.
Ausgangskonfiguration: Hauptserver RPi verbunden via FHEM2FHEM mit Remoteserver TuxRadio. Keine Auffälligkeiten im Logfile des TuxRadios. RPi Log-Einträge im 5 Sekundentakt:
2014.12.01 23:00:04 1: Error in CUL_MAX_SendQueueHandler: CUL TuxRadio_RC did not answer request for current credits. Waiting 5 seconds.
2014.12.01 23:00:09 1: Error in CUL_MAX_SendQueueHandler: CUL TuxRadio_RC did not answer request for current credits. Waiting 5 seconds.
2014.12.01 23:00:14 1: Error in CUL_MAX_SendQueueHandler: CUL TuxRadio_RC did not answer request for current credits. Waiting 5 seconds.
2014.12.01 23:00:19 1: Error in CUL_MAX_SendQueueHandler: CUL TuxRadio_RC did not answer request for current credits. Waiting 5 seconds.
2014.12.01 23:00:24 1: Error in CUL_MAX_SendQueueHandler: CUL TuxRadio_RC did not answer request for current credits. Waiting 5 seconds.

# $Id: fhem.pl 7097 2014-11-30 07:41:36Z rudolfkoenig $
# $Id: 00_CUL.pm 6980 2014-11-15 13:06:08Z rudolfkoenig $
# $Id: 14_CUL_MAX.pm 7067 2014-11-26 19:49:23Z mgehre $
# $Id: 93_FHEM2FHEM.pm 6203 2014-07-06 12:31:20Z rudolfkoenig $
# $Id: 10_MAX.pm 7068 2014-11-26 19:50:04Z mgehre $
Produktivsystem: Raspberry Pi 3, Add-On Board mit 1.8" TFT LCD, FHEM V5.8, miniCUL-WLAN, FS20, ESA2000, Oregon, Sonoff, JeeLink Clone, LaCrosse, EMT7110, 1-Wire, WiFi LED Controller, Yamaha AVR
Testumgebung: NanoPi Neo, ESP8266, HMIP, LaCrosseGateway, mapleCUL, Tablet UI, RaspberryMatic

Offline stgeran

  • Sr. Member
  • ****
  • Beiträge: 959
Ich weis nicht, ob es dazu gehört, bei mir ist fhem gestern gegen 23:00 komplett ausgestiegen und war erst über einen reboot des raspi über die Konsole wieder ins rollen zu bringen. Wenn nötig schaue ich heute Abend ins log zu diesem Zeitpunkt nach den letzten Meldungen.
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

Offline haufsolutions

  • New Member
  • *
  • Beiträge: 21
Schließe mich hier Mal an. Habe in den letzten Wochen immer Mal wieder beobachtet das er nachm CUL_MAX_Parse: len mismatch nicht mehr weiter macht, disconnected und das wars:

2015.02.22 02:01:18 3: set cm fakeWT MAX_0ad5a9 17.0 17.1
2015.02.22 02:01:18 1: CUL_MAX_Parse: len mismatch
2015.02.22 02:01:21 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL0)
2015.02.22 02:01:21 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.22 02:01:23 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.22 02:01:28 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.22 02:01:33 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.22 02:01:38 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.22 02:01:43 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.22 02:01:48 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.22 02:01:53 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.

2015.02.24 18:05:47 3: CUL_MAX_Parse: Re-Pairing device 0ad573 of type HeatingThermostat with serial KEQ0406120
2015.02.24 18:05:47 1: CUL_MAX_Parse: len mismatch
2015.02.24 18:05:50 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL0)
2015.02.24 18:05:50 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.24 18:05:52 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.24 18:05:57 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.24 18:06:02 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.24 18:06:07 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.
2015.02.24 18:06:12 1: Error in CUL_MAX_SendQueueHandler: CUL CUL0 did not answer request for current credits. Waiting 5 seconds.

Wie oben zu sehen ist nicht ganz ersichtlich wann das ganze passiert. Mehr oder weniger Zufall. Fazit shutdown restart hilft danach immer.
Bis man das allerdings immer detektiert ist man schon eingefroren  ;D daher habe ich mir einen kleinen Lösungsansatz programmiert für die 14_CUL_MAX.pm

 
if(2*$len+3 != length($rmsg)) { #+3 = +1 for 'Z' and +2 for len field in hex
    Log 1, "CUL_MAX_Parse: len mismatch";
    Log 1, "CUL_MAX_Parse: Something went wrong... going to restart.";
    fhem("shutdown restart");
    return $shash->{NAME};
  }

Der ideale Weg währe natürlich, wenn sich der CUL reconnected... aber ich hoffe mein fast and dirty Weg funktioniert auch  :D

Offline haufsolutions

  • New Member
  • *
  • Beiträge: 21
Scheint zu klappen. Grade beim Batteriewechsel erneut passiert:

2015.02.24 20:50:02 3: set  fakeWT MAX_0ad599 17.5 17.6 : Please define fakeWT first
2015.02.24 20:50:02 3: SendExtTemp_GWZ return value: Please define fakeWT first
2015.02.24 20:50:31 3: CUL_MAX_Parse: Re-Pairing device 0ad5a9 of type HeatingThermostat with serial KEQ0406174
2015.02.24 20:50:31 1: CUL_MAX_Parse: len mismatch
2015.02.24 20:50:31 1: CUL_MAX_Parse: Something went wrong... going to restart.
2015.02.24 20:50:31 0: Server shutdown
2015.02.24 20:50:35 1: Including fhem.cfg
2015.02.24 20:50:35 3: telnetPort: port 7072 opened
2015.02.24 20:50:36 3: WEB: port 8083 opened
....

Offline SirUli

  • Full Member
  • ***
  • Beiträge: 127
    • wolf-u.li
Ich habe das gleiche Problem - dankbarerweise läuft der Kram autark, sonst hätte es heute direkt wieder eins auf den Deckel gegeben... ;) Habe seit dem Update (ich habe 2015.02.23 23:10:20 das update mit der 10_MAX.pm gemacht) nur die folgende Zeile tausend mal drin:
2015.02.24 00:23:13 1: CUL_MAX_Parse: len mismatch
Das ging dann so den ganzen Tag...bis ich eben hier die Mailbenachrichtigung gesehen habe und mir böses schwante... ;)
FHEM auf RaspberryPI mit SCC 868Mhz (MAX!), SCC 868Mhz (SlowRF), SCC 433Mhz, Homematic - Verschiedene Netzwerk-Devices (Hue/Onkyo/LG)

Offline haufsolutions

  • New Member
  • *
  • Beiträge: 21
Ich habe das gleiche Problem - dankbarerweise läuft der Kram autark, sonst hätte es heute direkt wieder eins auf den Deckel gegeben... ;) Habe seit dem Update (ich habe 2015.02.23 23:10:20 das update mit der 10_MAX.pm gemacht) nur die folgende Zeile tausend mal drin:
2015.02.24 00:23:13 1: CUL_MAX_Parse: len mismatch
Das ging dann so den ganzen Tag...bis ich eben hier die Mailbenachrichtigung gesehen habe und mir böses schwante... ;)

Gabs ein Update? Ich hab seit de letzten FHEM Update im Nov/ Dez? kein Update mehr gemacht  :D
Hört sich bei dir aber auch nicht sehr berauschend an.

Offline gero

  • Sr. Member
  • ****
  • Beiträge: 593
Die Meldung
CUL_MAX_Parse: len mismatchhabe ich ca. 3 - 4- mal pro Tag im Log. Allerdings läuft bei mir alles stabil.

Laßt euch doch mal die Nachricht ausgeben, die den Fehler verursacht:
In der Datei 14_CUL_MAX.pm Zeile 264 von
    Log3 $hash, 1, "CUL_MAX_Parse: len mismatch";auf
    Log3 $hash, 1, "CUL_MAX_Parse: len mismatch ($rmsg)";abändern.
Ich glaube es gibt immer noch einen kleinen Bug in der CUL_ReadAnswer Funktion (00_CUL.pm). Meiner Meinung nach werden im Dispatchteil der Routine die \r Zeichen nicht entfernt und das führt zu Problemen in der Routine CUL_Parse. Ich habe bei mir jetzt mal den Code geändert und werde ihn zum Testen einige Zeit laufen lassen.

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

Offline gero

  • Sr. Member
  • ****
  • Beiträge: 593
Ich habe hier
http://forum.fhem.de/index.php/topic,36155.msg288168.html#msg288168
einen kleinen Patch für das Problem veröffentlicht.

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

Offline netwalk

  • Full Member
  • ***
  • Beiträge: 110
Hallo,

ich krame diesen Thread wieder hervor, da er meiner Meinung nach genau mein Problem beschreibt.

Ich habe vor einigen Tagen meinen CUBE deaktiviert, da ich durch ihn ständig Freezes hatte, die mein neues HMLGW disconnecten ließen.
Alle MAX Geräte habe ich mit einem CUL mit Firmware 1.66 gepairt. Dies funktionierte eigentlich ganz gut (mit entsprechender Credit-Wartezeit).
In der Regel laufen meine MAX HR im Auto-Modus, ich greife recht selten ein, nur zum Schlafen gehen durch setzen in den ECO-Modus mittels Taster.

Nun habe ich festgestellt, dass die WT bzw. HR nicht mehr reagierten, die Statusänderungen der FK jedoch einwandfrei angezeigt wurden.
Im Log fand ich folgende Einträge:

2016.12.30 06:49:02 1: Error in CUL_MAX_SendQueueHandler: CUL CUL1 did not answer request for current credits. Waiting 5 seconds.
2016.12.30 06:49:07 1: Error in CUL_MAX_SendQueueHandler: CUL CUL1 did not answer request for current credits. Waiting 5 seconds.
2016.12.30 06:49:12 1: Error in CUL_MAX_SendQueueHandler: CUL CUL1 did not answer request for current credits. Waiting 5 seconds.
2016.12.30 06:49:17 1: Error in CUL_MAX_SendQueueHandler: CUL CUL1 did not answer request for current credits. Waiting 5 seconds.
...

Ein "shutdown restart" brachte keine Änderung, nur ein "sudo reboot" des RasPi half.
Dieses Deaktivieren des CUL habe ich jetzt mehrfach erlebt, meistens nach ziemlich exakt 18 Stunden.

Sollte dieser Fehler nicht eigentlich behoben sein?
live long and prosper
netwalk
_______________________________________________
Rapberry Pi 3, Homematic mit HMLGW, RFXtrx433, DUOFERNSTICK, FBDECT, JEELINK

Offline szoller

  • Full Member
  • ***
  • Beiträge: 132
    • FHEM Discord
Ich muss das Thema auch wieder auskramen, das Problem tritt bei mir auch auf nun.

Ich bin von einem SCC2 mit rfmode MAX gewechselt zu einem als CUNO geflashten MAXCUBE (V 1.24.02 a-culfw Build: 208)

Sieht im Logfile dann so aus:
2017.06.15 19:12:39 1: 192.168.22.90:2323 disconnected, waiting to reappear (CUN_MAX)
2017.06.15 19:12:39 1: Error in CUL_MAX_SendQueueHandler: CUL CUN_MAX did not answer request for current credits. Waiting 5 seconds.
2017.06.15 19:12:44 3: CUN_MAX: Possible commands: BbCFiAZNEkGMKLUYRTVWXefhltxz
2017.06.15 19:12:44 1: 192.168.22.90:2323 reappeared (CUN_MAX)
2017.06.15 19:22:05 1: 192.168.22.90:2323 disconnected, waiting to reappear (CUN_MAX)
2017.06.15 19:22:05 3: CUN_MAX: Possible commands: BbCFiAZNEkGMKLUYRTVWXefhltxz
2017.06.15 19:22:05 1: 192.168.22.90:2323 reappeared (CUN_MAX)
FHEM 5.7 auf Raspberry Pi Model B mit Raspbian Linux | SCC 433Mhz | SCC 868 Mhz @ MAX | SCC 868 Mhz @slowRF

FHEM Discord Server: https://discord.gg/GE7mbED

 

decade-submarginal