FHEM Forum

FHEM - Hausautomations-Systeme => Homematic => Thema gestartet von: hermannk am 19 Mai 2014, 13:33:32

Titel: CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 19 Mai 2014, 13:33:32
Ich habe einen CUNO (V 1.58 CUNO868) über USB(!) an einen FHEM-Server (unter Ubuntu 14.04) angeschlossen. Ein HM-WDS10-TH-O sendet Daten, die zunächst ordnungsgemäß empfangen werden. Nach etwa 3 Stunden bricht der Empfang mit folgender Meldung ab:


2014.05.19 11:10:09 2: CUL1: unknown message ? (s0937A112123ABC206C3E is unknown) Use one of m B C F Z i A G M R T V W X O e f l t u H x E c q


Der String (s09??A112123ABC206C3E) variiert von Fall zu Fall leicht:


s0915A112123ABC206C3E
||||||||||||||||||||
||||||||||||||\\\\\\---------- see "define th CUL_HM 206C3E"
||||||||||||||
||||||||\\\\\\---------------- see "attr CUL1 hmId 123ABC"
||\\++++---------------------- variant: 0x15, 0x4e, 0x37
||  ||||
\\--\\\\---------------------- constant, compare to "09A112" when parsing messages in 10_CUL_HM.pm


Die Kommunikation läuft nach Eingabe von
rereadcfg
auf den telnet-port wieder an.

Was geht da schief?
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: martinp876 am 19 Mai 2014, 15:59:45
das Problem ist das "s" zu beginn. Bei HM sollte die CUL ein "A" senden.
Warum die CUL ein "s" sendet ist mir nicht klar.
Nach rereadCfg wird die CUL neu aufgesetzt und repariert - glauben ich jedenfalls
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 19 Mai 2014, 19:58:42
@martinp876:

Danke für den schnellen Hinweis. Inzwischen habe ich das Problem gewiresharkt. Die entscheidende Stelle ist die folgende:

   0 53583 2575.352508 C  95  31 URB_BULK      41304344 43383637 30323036 43334530 30303030 30303041 31343546 310d0a                                                   A0CDC8670206C3E00000000A145F1..                                 
448 53585 2575.451016 S  87  23 URB_BULK      41733039 32454131 31323132 33414243 32303643 33450a                                                                     As092EA112123ABC206C3E.                                         
458 56071 2647.288810 S  87  23 URB_BULK      41733039 32464131 31323132 33414243 32303643 33450a                                                                     As092FA112123ABC206C3E.                                         
   0 59433 2720.630717 C  95  31 URB_BULK      41304344 44383637 30323036 43334530 30303030 30303041 31343546 300d0a                                                   A0CDD8670206C3E00000000A145F0..                                 
709 59459 2720.733148 S  87  23 URB_BULK      41733039 32464131 31323132 33414243 32303643 33450a                                                                     As092FA112123ABC206C3E.                                         
   0 62817 2834.156456 C 101  37 URB_BULK      41304630 30383631 30323535 37423130 30303030 30304132 38423330 43303031 3431440d 0a                                     A0F0086102557B10000000A28B30C00141D..                           
119 62823 2834.239821 S  87  23 URB_BULK      41733039 32464131 31323132 33414243 32303643 33450a                                                                     As092FA112123ABC206C3E.                                         
   0 63145 2853.292582 C 163  99 URB_BULK      3f202873 30393246 41313132 31323341 42433230 36433345 20697320 756e6b6e 6f776e29 20557365 206f6e65 206f6620 6d204220 43 ? (s092FA112123ABC206C3E is unknown) Use one of m B C F Z i A G
  11 63147 2853.419039 S  87  23 URB_BULK      41733039 32464131 31323132 33414243 32303643 33450a                                                                     As092FA112123ABC206C3E.                                         
1205 63171 2855.330312 S  87  23 URB_BULK      41733039 33304131 31323132 33414243 32303643 33450a                                                                     As0930A112123ABC206C3E.                                         
1704 70907 3048.459690 S  87  23 URB_BULK      41733039 33314131 31323132 33414243 32303643 33450a                                                                     As0931A112123ABC206C3E.                                         
888 78977 3321.229854 S  87  23 URB_BULK      41733039 33324131 31323132 33414243 32303643 33450a                                                                     As0932A112123ABC206C3E.                                         


Die Spalten des Protokolls sind wie folgt zu lesen:

Paket #62823 ist übrigens die Weiterleitung der Antwort eines HM-CC-RT-DN.

Zur Sache: Der CUNO wird alle 150 ms gepollt. Er antwortet in etwa 0.2 ms. Die Antwortpakete habe ich ausgefiltert, sie hätten das Protokoll nur aufgebläht. Von Zeit zu Zeit (siehe die Pakete #56071, #63171, #70907, #78997) erhöht FHEM seinen Message Counter. Das scheint den CUNO nicht zu stören, warum auch? Bei Paket #63145 passiert's: Nachdem der CUNO mal wieder 120 Polls hat über sich ergehen lassen hat, platzt ihm der Kragen und er wirft das erste Zeichen weg. Dass es ordnungsgemäß gesendet worden ist, wird durch usbmon/tshark bestätigt. Es sieht also so aus, als würde der USB Empfang des CUNO Zeichen verlieren. Besonders ärgerlich ist, dass der CUNO anschließend überhaupt nicht mehr antwortet. Das ist nicht nur in diesem Zusammenhang sehr wesentlich.

Wie schon eingangs beschrieben, tritt das Problem etwa alle drei Stunden auf.
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: martinp876 am 20 Mai 2014, 08:32:45
Hallo Hermann,

die message ist eine aufwach-message, die einem "wakeup" device sagen soll, dass es wach bleiben soll, um daten zu empfangen.
Dein Device antwortet aber nicht.

Evtl kannst du die CUNO wiederbeleben, wenn du den rfmode neu setzt.
Generell ist es ein Problem der CUNO, wie du schon debuggt hast - solltest du dort einwerfen.

Falls es mit dem Setzen des rfmode wieder funktioniert kannst du es vorübergehend als notify einbauen.

Gruss Martin
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: mgernoth am 20 Mai 2014, 10:31:04
Hallo,

nur kurz: Ich habe gestern Abend versucht rauszukriegen, was hier schief läuft und kann mir das eigentlich nur durch zwei Dinge erklären:
* Die Firmware macht irgendetwas anderes (OneWire evtl.?) und verliert so das erste empfangene Byte über die serielle Schnittstelle. Ist aber eher unwahrscheinlich, da der serielle Empfang interruptgetrieben arbeitet.
* Die Baudrate zwische USB-seriell-Konverter (auf dem CUNO) und AVR ist leicht unterschiedlich und der AVR synct sich manchmal nicht auf das erste Byte einer Nachricht ein. Du öffnest das Gerät mit 38400, oder?

Und nur um sicherzugehen: Das Problem tritt auch mit 1.57 auf? In 1.58 habe ich den seriellen Empfangspuffer durch Interruptsperren gegen gleichzeitige Zugriffe geschützt, nicht das ich hier irgendwas kaputtgemacht habe... Aber mit der alten Version in 1.57 waren z.B. OTA-Updates unmöglich, da hier sehr viele Daten verloren gingen.

EDIT: Der Ethernettreiber sperrt für einen längeren Zeitraum die Interrupts. Hier könnte tatsächlich dann das erste Byte verloren gehen. Ich nehme mal an, da steckt kein Netzwerkkabel drin und der CUNO versucht immer mal wieder per DHCP eine Adresse zu bekommen?

Gruß
  Michael
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: martinp876 am 20 Mai 2014, 13:11:32
und nicht vergessen:

http://www.fhemwiki.de/wiki/HM-CFG-LAN_LAN_Konfigurations-Adapter#CUL.2FCUN.28O.29
keine CUNO über Ethernet - der Stack ist zu ungenau (timing)
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 20 Mai 2014, 15:30:46
Hallo Michael,

Zitat von: mgernoth am 20 Mai 2014, 10:31:04
* Die Firmware macht irgendetwas anderes (OneWire evtl.?) und verliert so das erste empfangene Byte über die serielle Schnittstelle. Ist aber eher unwahrscheinlich, da der serielle Empfang interruptgetrieben arbeitet.

Am OneWire habe ich nichts angeschlossen.

Zitat von: mgernoth am 20 Mai 2014, 10:31:04
Du öffnest das Gerät mit 38400, oder?

Ja:
define CUL1 CUL /dev/ttyUSB0@38400 1122

Zitat von: mgernoth am 20 Mai 2014, 10:31:04Und nur um sicherzugehen: Das Problem tritt auch mit 1.57 auf?

Da ist es wieder, das schlechte Gewissen ;). Ich habe den CUNO in dieser Woche gekauft und direkt mit 1.58 angefangen. Ich werde ihn mal downgraden.

Zitat von: mgernoth am 20 Mai 2014, 10:31:04EDIT: Der Ethernettreiber sperrt für einen längeren Zeitraum die Interrupts. Hier könnte tatsächlich dann das erste Byte verloren gehen. Ich nehme mal an, da steckt kein Netzwerkkabel drin und der CUNO versucht immer mal wieder per DHCP eine Adresse zu bekommen?

Das ist eine offene Baustelle bei mir. Ich hatte den CUNO ins Netzwerk gesteckt und im Protokoll meines DHCP-Servers vergeblich nach Meldungen gesucht, die mir die Adresse des CUNO verraten würden. Nachdem ich nichts gefunden hatte, habe ich arp (unter Ubuntu 14.04) eingegeben und

Address                  HWtype  HWaddress           Flags Mask            Iface
192.168.0.244            ether   a4:50:55:01:10:1a   C                     eth0
.


erhalten. Da die MAC von busware.de registriert ist, hatte ich meinen CUNO. Wohlgemerkt, 244 ist nicht im Bereich der DHCP Adressen. Warum hatte DHCP nicht funktioniert? Woher kommt die 192.168.0.244? Woher kennt der CUNO die Netmask?

Des weiteren hatte ich danach über telnet 192.168.0.244 2323 noch Wid00 eingegeben. Rid antwortete danach auch mit 00 und Ria zeigte 192.168.0.244. Damit konnte ich das Thema nach hinten schieben und mein DHCP Server hat auch keine Anfragen protokolliert. Der Switch (CISCO SG200) meldet 10M halfduplex.

Ja, es steckt ein Netzwerkkabel drin. Aber die Abstürze passieren, wenn ich nichts an der Telnet Schnittstelle mache.

Übrigens, es fehlte in acht von acht Abstürzen das erste Bit.

Dennoch verbleibt eine Unsicherheit. Nach allem ist es sehr unwahrscheinlich, dass DHCP Anfragen laufen, aber ich werde noch mit tshark ausschließen, dass da im Fehlerfall Netzwerkverkehr auftritt.
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 21 Mai 2014, 10:34:55
Hallo Michael,

Zitat von: mgernoth am 20 Mai 2014, 10:31:04
EDIT: Der Ethernettreiber sperrt für einen längeren Zeitraum die Interrupts. Hier könnte tatsächlich dann das erste Byte verloren gehen. Ich nehme mal an, da steckt kein Netzwerkkabel drin und der CUNO versucht immer mal wieder per DHCP eine Adresse zu bekommen?

Ich habe das Ethernet-Kabel rausgezogen und der Fehler tritt immer noch auf. Als Nächstes ist der Downgrade dran.

Grüße

Hermann
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 21 Mai 2014, 13:55:54
Zitat von: hermannk am 21 Mai 2014, 10:34:55
Als Nächstes ist der Downgrade dran.

Ein Problem: http://culfw.de/culfw-1.57.tar.gz (http://culfw.de/culfw-1.57.tar.gz) gibt's nicht (mehr). Woher bekomme ich die alte Version?

Grüße

Hermann
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 05 Juni 2014, 15:45:28
Hallo Michael,

Zitat von: mgernoth am 20 Mai 2014, 10:31:04Und nur um sicherzugehen: Das Problem tritt auch mit 1.57 auf?

Ich habe versucht, diesen Punkt zu klären, bin aber daran gescheitert, dass ich keine Version 1.57 im Netz gefunden habe. Habe ich da was übersehen?
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 06 Juni 2014, 10:00:26
Hallo Martin,

Zitat von: martinp876 am 20 Mai 2014, 08:32:45Evtl kannst du die CUNO wiederbeleben, wenn du den rfmode neu setzt.

Falls es mit dem Setzen des rfmode wieder funktioniert kannst du es vorübergehend als notify einbauen.

Ich habe Folgendes versucht:

define unfreeze notify .*:.*dead.* { fhem "attr CUL1 rfmode HomeMatic" }

Nur interessenshalber: Wäre das so richtig?

Es hat nicht funktioniert. Wie auch immer, ich habe ein Shell-Script, dass einen rereadcfg an den Port 7072 schickt. Und damit wirkt sich der Fehler nicht mehr aus. Ich habe also keinen Zeitdruck mehr dahinter.

Hermann
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: mgernoth am 07 Juni 2014, 10:51:22
Hallo Hermann,

Zitat von: hermannk am 05 Juni 2014, 15:45:28
Ich habe versucht, diesen Punkt zu klären, bin aber daran gescheitert, dass ich keine Version 1.57 im Netz gefunden habe. Habe ich da was übersehen?

Nein, gibts anscheinend tatsächlich nicht mehr.  Welchen CUNO hast Du denn genau, dann bauche ich die 1.57 nochmal.

Gruß
  Michael
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: hermannk am 09 Juni 2014, 15:34:14
Gelöst

Als ich FHEM am 2014-05-09 heruntergeladen hatte, war mir nicht bewusst, dass die neueste Datei in der Packung vom 2013-09-29 (Nr. 3971) war. Das wurde mir erst klar, als ich versuchte, einen     
HM-ES-PMSw1-Pl einzubinden. Durch das Update am 2014-06-06 wurde (z.B.) 10_CUL_HM.pm von 5759 auf 9499 Zeilen (Dateidatum 2014-06-05, Nr. 6071) vergrößert. Da ist wohl kein Stein auf dem anderen geblieben. Immerhin, nach dem Update war der Fehler weg.

Anmerkung: Nach dem Wireshark Protokoll war ich davon ausgegeangen, dass das Problem in culfw war.
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: noansi am 10 Juni 2014, 05:56:18
Hallo Michael,


genau das gleiche Problem beschäftigt mich bei meinen Änderungen und Tests mit der TimeStamp Erweiterung bei der CUL.

Siehe auch: http://forum.fhem.de/index.php/topic,24436.0.html (http://forum.fhem.de/index.php/topic,24436.0.html)

Dabei beobachte ich das auch, das solche Meldungen kommen. Und habe auch beobachtet, dass anscheinend auch merkwürdige Dinge als Eingabe interpretiert (unbekannt gemeldet) werden, die aus dem  Ausgabestrom stammen müssten. So z.B. ist mal der Tickcounter der Uhr als Hexwert aufgetaucht (er war zu langsam für meine Timestamp, passte vom Faktor zum Tickcounter).

Ich habe beim Stand V1.58 aufgesetzt. Gegen gleichzeitigen Aufruf im Interrupt scheint mir Interpretation der Eingabe nicht zu sein. Der cdctask wird bei der CUL in der Hauptschleife aber auch im USB Interrupt aufgerufen.

Den wahren Grund habe ich aber noch nicht finden können. Was hattest Du geändert?


Gruß, Ansgar.
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: JoWiemann am 10 Juni 2014, 08:45:44
Zitat von: hermannk am 21 Mai 2014, 13:55:54
Ein Problem: http://culfw.de/culfw-1.57.tar.gz (http://culfw.de/culfw-1.57.tar.gz) gibt's nicht (mehr). Woher bekomme ich die alte Version?


Im Sourceforge finde auch ich nur http://sourceforge.net/p/culfw/code/HEAD/tree/tags/CUL_VER_155/.

Eine 1.57 hat es wohl nicht als offiziellem Tag gegeben, warum auch immer.

Grüße Jörg
Titel: Antw:CUL1: unknown message ? (s0937A112123ABC206C3E is unknown)
Beitrag von: mgernoth am 06 Juli 2014, 13:34:26
Hallo Ansgar,

Zitat von: noansi am 10 Juni 2014, 05:56:18
Ich habe beim Stand V1.58 aufgesetzt. Gegen gleichzeitigen Aufruf im Interrupt scheint mir Interpretation der Eingabe nicht zu sein. Der cdctask wird bei der CUL in der Hauptschleife aber auch im USB Interrupt aufgerufen.

Den wahren Grund habe ich aber noch nicht finden können. Was hattest Du geändert?

Meine Änderung war diese hier: http://sourceforge.net/p/culfw/code/406/

Btw, Version 1.57 gibts hier: http://sourceforge.net/p/culfw/code/385/tree/trunk/culfw/Devices/

Gruß
  Michael