CUL HM empfängt nicht oder sendet Empfangsdaten nicht an den Rechner

[noansi]

Hallo,

da Martin meinte, es wäre kein CUL_HM Problem versuche ich es mal hier.

Ich habe Empfangsprobleme mit meinem CUL an einem RaspBerry Pi.

Jetzt hat sich der glückliche Zufall ergeben, dass ich es mitloggen konnte (sogar verbose 5):

Code Auswählen Erweitern

2014.05.04 11:04:44.319 5: CUL/RAW: /A0CF28670206B0700000000CB3035

2014.05.04 11:04:44.321 4: CUL_Parse: CUL_0 A 0C F2 8670 206B07 000000 00CB3035 -47.5
2014.05.04 11:04:44.323 5: CUL_0 dispatch A0CF28670206B0700000000CB30::-47.5:CUL_0
2014.05.04 11:04:48.317 5: CUL/RAW: /A162686532156E4000000004100B842009043002844FFD8EF

2014.05.04 11:04:48.319 4: CUL_Parse: CUL_0 A 16 26 8653 2156E4 000000 004100B842009043002844FFD8EF -82.5
2014.05.04 11:04:48.321 5: CUL_0 dispatch A162686532156E4000000004100B842009043002844FFD8::-82.5:CUL_0
2014.05.04 11:22:25.880 4: CUL_send:  CUL_0C0 D     
2014.05.04 11:22:25.893 5: CUL/RAW (ReadAnswer): C0D = 21 / 33

2014.05.04 11:22:25.895 4: CUL_send:  CUL_0C0 E     
2014.05.04 11:22:25.907 5: CUL/RAW (ReadAnswer): C0E = 65 / 101

2014.05.04 11:22:25.909 4: CUL_send:  CUL_0C0 F     
2014.05.04 11:22:25.921 5: CUL/RAW (ReadAnswer): C0F = 6A / 106

2014.05.04 11:22:25.922 4: CUL_send:  CUL_0C1 0     
2014.05.04 11:22:25.935 5: CUL/RAW (ReadAnswer): C10 = C8 / 200

2014.05.04 11:22:25.936 4: CUL_send:  CUL_0C1 B     
2014.05.04 11:22:25.948 5: CUL/RAW (ReadAnswer): C1B = 43 / 67

2014.05.04 11:22:25.950 4: CUL_send:  CUL_0C1 D     
2014.05.04 11:22:25.962 5: CUL/RAW (ReadAnswer): C1D = 91 / 145

2014.05.04 11:33:35.145 4: CUL_send:  CUL_0X     
2014.05.04 11:33:35.157 5: CUL/RAW (ReadAnswer): 21  900

2014.05.04 11:34:33.329 3: set CUL_0 raw B
2014.05.04 11:34:33.330 4: CUL_send:  CUL_0B     
2014.05.04 11:34:34.332 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)
2014.05.04 11:35:35.842 4: CUL_send:  CUL_0X     
2014.05.04 11:37:25.310 3: Setting CUL_0 baudrate to 9600
2014.05.04 11:37:25.325 1: /dev/ttyACM0 reappeared (CUL_0)
2014.05.04 11:37:25.427 4: CUL_send:  CUL_0V     
2014.05.04 11:37:25.439 5: CUL/RAW (ReadAnswer): V 1.58 CUL868

2014.05.04 11:37:25.441 4: CUL_send:  CUL_0?     
2014.05.04 11:37:25.453 5: CUL/RAW (ReadAnswer): ? (? is unknown) Use one of B C F i A Z E G M K U R T V W X e f m l t u x

2014.05.04 11:37:25.456 3: CUL_0: Possible commands: BCFiAZEGMKURTVWXefmltux
2014.05.04 11:37:25.458 4: CUL_send:  CUL_0X2 1     
2014.05.04 11:37:25.469 4: CUL_send:  CUL_0Ar     
2014.05.04 11:37:25.482 4: CUL_send:  CUL_0T0 1     
2014.05.04 11:37:25.494 5: CUL/RAW (ReadAnswer): 1034

2014.05.04 11:37:25.496 5: GOT CUL fhtid: 1034
2014.05.04 11:37:38.742 5: CUL/RAW: /A0CDF8670206A4E000000007B4124

2014.05.04 11:37:38.744 4: CUL_Parse: CUL_0 A 0C DF 8670 206A4E 000000 007B4124 -56
2014.05.04 11:37:38.746 5: CUL_0 dispatch A0CDF8670206A4E000000007B41::-56:CUL_0
2014.05.04 11:37:38.877 5: CUL/RAW: /A0C6B867025F83E00000000864916

Zum Nebenschauspiel:
11:04 letzte Empfangsnachricht vom CUL. (Von meinen TH Sensoren sollten spätestens nach 3 Minuten wieder Daten kommen)
11:22 ich teste, ob der CUL noch lebt und fordere ccconf an. -> CUL antwortet?!?
11:33 ich teste, ob das Sendelimit erreicht ist -> CUL antwortet alles sei gut?!?
11:34 ich versuche einen Reboot des CUL -> den macht er wohl, aber er wird anschließend nicht mehr erkannt oder die Schnittstelle nicht neu geöffnet?!?
11:37 ich ziehe den CUL USB Stecker und stecke ihn wieder neu an -> er wird brav erkannt und sendet auch wieder seine Empfangsdaten an den Rechner

Neuer Test Reboot in normalen Empfangszustand:

Code Auswählen Erweitern

2014.05.04 11:56:13.316 5: CUL/RAW: /A163D86532157C8000000004100DC4200D743000544FFFB0D

2014.05.04 11:56:13.318 4: CUL_Parse: CUL_0 A 16 3D 8653 2157C8 000000 004100DC4200D743000544FFFB0D -67.5
2014.05.04 11:56:13.320 5: CUL_0 dispatch A163D86532157C8000000004100DC4200D743000544FFFB::-67.5:CUL_0
2014.05.04 11:56:18.129 3: set CUL_0 raw B
2014.05.04 11:56:18.131 4: CUL_send:  CUL_0B     
2014.05.04 11:56:19.132 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)

Wieder wird er nach Soft-Reboot nicht erkannt.

... [Edit] diesmal Reboot Versuch in normalem Empfangszustand mit B00, wie es sein sollte, wenn man die culfw reference richtig gelesen hat:

Code Auswählen Erweitern

2014.05.04 13:46:49.926 5: CUL/RAW: /A0C33867025F90B000000008A3819

2014.05.04 13:46:49.928 4: CUL_Parse: CUL_0 A 0C 33 8670 25F90B 000000 008A3819 -61.5
2014.05.04 13:46:49.930 5: CUL_0 dispatch A0C33867025F90B000000008A38::-61.5:CUL_0
2014.05.04 13:47:04.672 3: set CUL_0 raw B00
2014.05.04 13:47:04.674 4: CUL_send:  CUL_0B0 0     
2014.05.04 13:47:05.665 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)

aber auch damit wird der CUL anschließend nicht wieder erkannt?!? Nur Hardreset mit Stecker hilft.

CUL Firmware 1.58.

Check im syslog meines Raspbery Pi, auf dem der FHEM läuft, zeigt keine Einträge bis zum Hardreset CUL mit Stecker ziehen.

Offenbar zeigen sich hier 2 Probleme:

- der CUL sendet spontan keine Empfangsdaten mehr an den Rechner, lebt aber noch (LED blinkt weiter und Anworten gibt er)
- nach einem Soft-Reboot des CUL wird dieser nicht neu erkannt

Hast jemand Erklärungen dafür? Kann ich noch was loggen, um Unklarheiten beseitigen zu helfen?

Braucht das 00_CUL.pm vielleicht noch einen Exception Handler (falls da überhaupt was mit Fehler passiert)? Wenn ich es im Code richtig verstehe, dann muss es mit select über FD einfach ohne Fehler klappen, sonst geht nix mehr?!? Oder habe ich da was übersehen?

Vielen Dank und Gruss,

Ansgar.

[Puschel74]

Hallo,

pack doch mal bitte alles was kein Text ist in Code-Tags oder Zitat-Tags.
Dann heben sich die Logeinträge schonmal optisch vom übrigen Text ab und etwaige Helfer kommen leichter zurecht.
Danke.

Grüße

P.S.: Nein, ich kann dir leider nicht helfen mir ist nur die Textwand aufgefallen 
Edith: Aber man zumindest versuchen den Helfern das lesen leichter zu machen.

[rudolfkoenig]

- ich verstehe nicht, inwieweit das Log irgendetwas beweisen soll. Ich sehe, dass man bei einem auf HomeMatic gestellten CUL diverse CC1101 Register abgefragt hat, und dass das CUL ein HM Telegramm empfangen und an FHEM weitergereicht hat.
- B00 funktioniert bei meinem CUL V1.58
- bitte ohne tieferen Verstaendnis von FHEM keine komische Schlagwoerter (Exception handler, etc) verwenden

[noansi]

Hallo Rudolf,

- ich verstehe nicht, inwieweit das Log irgendetwas beweisen soll. Ich sehe, dass man bei einem auf HomeMatic gestellten CUL diverse CC1101 Register abgefragt hat, und dass das CUL ein HM Telegramm empfangen und an FHEM weitergereicht hat.

-Du musst einen Blick auf die Uhrzeit werfen im ersten Log Teil werfen. Die letzten beiden Empfangstelegramme sind angekommen, in normalem Zeitraster bis 11:04 (die Zeit davor kommen in kurzen Abständen von unter 2 Minuten Telegramme). Dann kommt nichts mehr bis 11:22, wo ich manuell die Abfragen starte, die auch beantwortet werden.
Bei 14 TH Sensoren ist eine 18 Minuten Pause doch schon schwer zu verstehen?!?
In meinen Plots sehe ich bisweilen knapp 2-Stündige Aussetzer. Aber irgendwie und irgendwann fängt es sich wieder. Durch heftiges Spielen an der FHEM Oberfläche mit mehreren Plotansichten gleichzeitig kommt es mir provozierbar vor (also mit Last auf dem Pi).

- nach einem disconnected muss laut code beim eingestellten verbose level auch der reconnect wieder angezeigt werden (wir es auch im log). Ein B00 sollte dafür sorgen, dass das ausgelöst wird. Und das nicht erst nach einer Minute oder länger, nach der ich den CUL manuell abgezogen und neu angesteckt habe. Mein B00 versuch zeigt den reconnect nur nicht mehr und Telegramme kommen auch nicht.

Außerdem habe ich auch zwei HM Dimmer, die ich in diesem Problem-Zustand auch nicht ansteuern kann, sie reagieren dann nicht auf meine Setz Befehle.

Das muss alles nicht am CUL liegen, sondern kann auch an dem Linux auf dem Raspberry Pi liegen, falls da was mit der serielln Schnittstelle oder USB schief geht.
Zumindest kann ich sagen, dass mit einem "shutdown restart" auch die CUL Verbindung wieder geheilt wird. Oder durch Abziehen und neu Einstecken des CUL.

Um das tiefere FHEM Verständnis bemühe ich mich und bin in fhem.pl in sub MAIN auf ExceptFn gestossen und hoffte, das damit vielleicht was zu machen ist.
Kann ich noch was loggen, um das Verständnis zu fördern?

Gruss und Danke,

Ansgar.

[rudolfkoenig]

Jetzt verstehe ich dein Problem besser, leider habe ich keine direkten Ideen. Die abgefragten CC1101 Werte sind zwar etwas willkuerlich, liefern aber die im culfw/rf_asksin.c eingestellten Werte zuerueck. Eventuell hilft es dir das TI CC1101 pdf zu studieren, war in meinem Fall aber zeitintensiv.

ExceptFn bietet einem Modul an ueber das globale select auch das except-Prameter zu verwenden. Wuerde mich sehr ueberraschen, wenn in diesem Falls das eine Bedeutung haette, und hat mit "Exception Handling" im ueblichen Sinne nichts zu tun.

[noansi]

Hallo Rudolf,

ich habe es testweise mal mit ExceptFn probiert. Aufgerufen wird sie aber nie. Schade. Da passiert einfach nichts greifbares. Auch die Linux Kernel messages liefern keinen Hinweis.

Nun habe ich eine neue Idee einer ReadyTimeoutFn. Wenn nach einem einstellbaren Timeout die ReadyFn z.B. für den CUL nicht von MAIN aufgerufen wird, soll die ReadyTimeoutFn aufgerufen werden in der in meinem bzw. CUL Fall ein Disconnect ausgelöst wird, was dann hoffentlich zu einer "Spontanheilung" führt durch Schließen und wieder Öffnen der seriellen Schnittstelle. Respektive dann auch indirekt deutlich machen würde, dass etwas nicht richtig mit der seriellen Schnittstelle oder dem Gerät funktioniert.

Das müsste in MAIN eingebaut werden. Und dann mit der ReadyTimeoutFn beim jeweiligen Gerät genutzt werden.

Spricht das einen Wunsch bei Dir an, daraus eine generelle Funktion in fhem.pl (und 00_CUL.pm) einzubauen?

Gruss, Ansgar.

[rudolfkoenig]

Spricht das einen Wunsch bei Dir an...

Nein, ich will nicht generische Funktionen fuer einen Sonderfall einbauen, sowas kann man auf Benutzerebene mit Watchdog o.ae. loesen. Es ist gar nicht erwiesen, dass dein Problem dadurch vollstaendig behoben wird. Ich vermute eher kaputte Komponenten, da ich das Problem in dieser Form zum ersten mal hoere, aber nach meiner Schaetzung ueber tausend FHEM-Anwender ein RPi mit HomeMatic betreiben.

[noansi]

Hallo Rudolf,

vielen Dank für den Tipp mit dem watchdog.

Ich habe seit gestern Abend einen watchdog:

Code Auswählen Erweitern

define CULW watchdog CUL_HM 00:05:00 SAME setstate CUL_0 disconnected

laufen.

Im Log tauchen nun 2 Einträge auf:

Code Auswählen Erweitern

2014.05.07 02:49:29 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)
2014.05.07 02:49:29 1: /dev/ttyACM0 reappeared (CUL_0)
2014.05.07 03:19:36 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)
2014.05.07 03:19:36 1: /dev/ttyACM0 reappeared (CUL_0)

Die zeigen aber keine Empfangsaussetzer (in den Sensor Logs kommt zu den Zeiten was) sondern nur, dass sich so lange keine Signaländerung bei allen Sensoren ergeben hat, so das CUL_HM keine Events generiert hat. CUL selber sorgt leider für keine Events (beobachtet im Event Monitor), die ich mit dem watchdog filtern könnte.

Übersehe ich eine Möglichkeit, mit dem watchdog nur den CUL zu überwachen?

Danke und Gruss,

Ansgar.

[rudolfkoenig]

setstate CUL_0 disconnected

Ich vermute das bewirkt nicht das, was du erhoffst.

Watchdog ist kein Wunderding, es reagiert auf das, was auch im Event-Monitor zu sehen ist.

Und bin immer noch der Ansicht, mit einem regelmaessigen Tritt kaputte Hardware
zum Leben zu erwecken nicht die richtige Methode ist, und ich will diese Methode
nicht zu Perfektion verhelfen.

[noansi]

Hallo Rudolf,

ja, Du hast recht, zu früh gefreut. Ich habe in DevIO_OpenDev übersehen, dass die ReadyFn des CUL aus der Liste entfernt wird, wenn er in die select Liste eingetragen wird. Somit wird disconnected nicht reagiert.
Also muss ich es selbst mal testweise so einbauen, wie ich es mir vorgestellt habe. Macht halt Updates aufwändiger. Aber dafür kann ich hoffentlich das Problem weiter einkreisen.

Heute wieder von 14:33Uhr bis 15:31Uhr kein einziger Sensor Log Eintrag bei allen Homematik Sensoren. Der Watchdog hat nichts gebracht, da die ReadFn nicht aufgerufen wird.
Ein parallel laufender ELV USB-WDE1 hat dagegen wunderbar in diesem Zeitraum seine Sensoren empfangen. Daher schließe ich einen massiven Störsender aus. USBWX habe ich übrigens auf Devio.pm umgeschrieben, so dass er die Funktionen so werwendet, wie CUL es auch tut. Er zeigt auch schon mal diese disconnects, aber nicht so seltsame Aussetzter mit Selbstheilung.

Und das ist, was ich nicht an dem Problem mit dem CUL verstehe. 1 Stunde nichts und dann kommt wieder was, als sei nichts gewesen. Als ich es live beobachten konnte blinkte die CUL LED auch brav vor sich hin. Dann muss er ja noch aktiv sein und der CUL interne Watchdog würde ihn auch nicht erst nach einer Stunde wiederbeleben. Und der Empfänger soll eine Stunde nicht funktionieren und dann wieder.
Zu dieser Uhrzeit hat auch die Sonne keine Chance für ungewöhnliche Temperaturen zu sorgen, um merkwürdiges Verhalten auszulösen.

Dann bliebe als Hardware noch der USB Anschluss am Raspberry Pi. Aber was holt den dann nach einer Stunde wieder ins Leben? Und warum hinterläst das absolut keine Spuren in den systemlogs von linux?
Warum kein USB disconnect? Sonnentechnich gleiche Situation, wie beim CUL, als auch kein Grund. RasPis sysstat zeigtt auch eine maximale Temperatur von 43,35°C un das um 9:30.

Das lässt mich am Hardwareproblem zweifeln. Ich werd aber mal testweise auch den RasPi austauschen. Einen weiteren CUL habe ich leider nicht.

Übrigens fallen die Aussetzer bei normaler plot Darstellung auch gar nicht so sehr auf. Aber ich hab meine Plots auf Treppenstufen umgestellt und daher sehe ich sie sehr deutlich bei größeren Temperaturänderungen. In sofern reduziert sich für mich die Anzahl der RasPi Nutzer, die sich darüber beklagen.

Gruß, Ansgar.

[rudolfkoenig]

Ein einem reboot des CULs glaube ich auch nicht, das kann man aber leicht mit uptime feststellen.
Funktioniert das CUL auf einem "richtigen" Rechner (d.h. einer mit mehr Strom) zuverlaesslich?

[noansi]

Hallo Rudolf,

den Uptime check hatte ich schon mal gemacht. Da war kein Reboot dran auszumachen.

Die Stromversorgung habe ich mir auch schon mal durch den Kopf gehen lassen und mir schon vor genommen, ein etwas dickeres Netzteil direkt löttechnisch mit dem Pi zu verbinden.
Zumindest kann ich schon mal sagen, dass es keinen Unterschied macht, ob ich den CUL mit einem 1,5m USB Kabel am Pi betreibe oder ein weiteres zu Verlängerung auf 3m benutze.

Mal sehen, ob es hilft.

Gruß, Ansgar.

[noansi]

Hallo Rudolf,


ich habe nun mal eine "ReadTimeoutFn" in fhem.pl in MAIN eingebaut.

Ich hoffe, Du lässt das doch noch in fhem.pl einfließen. Immerhin bringt es noch zusätzlich Timinginformationen zu ReadFn, was für Modulentwicklung durchaus interessant ist.
Das letzte, mittlere und maximale Aufrufintervall in Sekunden für ReadFn wird bestimmt, sowie die Häufigkeit des Timeoutauftretens und in Internals zum Gerät dargestellt.

Der original Code ist zitiert und meine Ergänzungen als Code dargestellt.

################################################
# Main Loop
sub MAIN {MAIN:};               #Dummy

my $errcount= 0;
while (1) {
  my ($rout,$rin, $wout,$win, $eout,$ein) = ('','', '','', '','');

  my $timeout = HandleTimeout();

Code Auswählen Erweitern

# handle device not sending data until a timeout defined by the device module
my $acttime = gettimeofday();

foreach my $p (keys %selectlist) {
    my $hash = $selectlist{$p};

Code Auswählen Erweitern

# handle device not sending data until a timeout defined by the device module
# shows also a little statistics for execution of the device ReadFn
#
# in device module do
# define $hash->{LastReadTimeout} with the read timeout in seconds
# define $hash->{ReadTimeoutFn} with the reference to the handler function for read timeouts
#
# example for CUL:
#
# add timeout function
# sub CUL_ReadTimeoutFn($)
# {
# my ($hash) = @_;
# my $name = $hash->{NAME};
#
# Log3 $name, 1, "CUL_ReadTimeoutFn: $name Read timeout seen on serial port";
#
# DevIo_Disconnected($hash);
#
# return undef;
# }
#
# in CUL_Define function add
# $hash->{ReadTimeoutFn} = \&CUL_ReadTimeoutFn;
# $hash->{LastReadTimeout} = 300;  #300 seconds timout. Reasonable for e.g. Homematic TH Sensors, continously sending data in about 2 minutes interval
#
# in CUL_Undef function add
# delete($hash->{ReadTimeoutFn});
# delete($hash->{LastReadTime});
# delete($hash->{LastReadTimeout});
# delete($hash->{LastReadTDmax});
# delete($hash->{LastReadTDmean});
# delete($hash->{LastReadTDN});
# delete($hash->{LastReadTD});
# delete($hash->{LastReadTimeoutDetected});

if(defined($hash->{LastReadTimeout}))
{
if (defined($hash->{LastReadTime}))
{
# handle timeout of receiving data from device
my $td = $acttime - $hash->{LastReadTime};
if($td > $hash->{LastReadTimeout})
{
Log 1, "Try ReadTimeoutFn for $hash->{NAME}";
$hash->{LastReadTimeoutDetected}++;
$hash->{ReadTimeoutFn}->($hash) if(defined($hash->{ReadTimeoutFn}));
$hash->{LastReadTime} = $acttime; #needed, else timeout forever after timeout
next;
}
}
}

if(defined($hash->{FD})) {
      vec($rin, $hash->{FD}, 1) = 1
        if(!defined($hash->{directWriteFn}));
      vec($win, $hash->{FD}, 1) = 1
        if(defined($hash->{directWriteFn}) || defined($hash->{$wbName}));
    }
    vec($ein, $hash->{EXCEPT_FD}, 1) = 1
        if(defined($hash->{"EXCEPT_FD"}));
  }
  $timeout = $readytimeout if(keys(%readyfnlist) &&
                              (!defined($timeout) || $timeout > $readytimeout));
  $timeout = 5 if $winService->{AsAService} && $timeout > 5;
  my $nfound = select($rout=$rin, $wout=$win, $eout=$ein, $timeout);

  $winService->{serviceCheck}->() if($winService->{serviceCheck});
  CommandShutdown(undef, undef) if($sig_term);

  if($nfound < 0) {
    my $err = int($!);
    next if($err==0 || $err==4); # 4==EINTR

    Log 1, "ERROR: Select error $nfound ($err), error count= $errcount";
    $errcount++;

    # Handling "Bad file descriptor". This is a programming error.
    if($err == 9) {  # BADF, don't want to "use errno.ph"
      my $nbad = 0;
      foreach my $p (keys %selectlist) {
        my ($tin, $tout) = ('', '');
        vec($tin, $selectlist{$p}{FD}, 1) = 1;
        if(select($tout=$tin, undef, undef, 0) < 0) {
          Log 1, "Found and deleted bad fileno for $p";
          delete($selectlist{$p});
          $nbad++;
        }
      }
      next if($nbad > 0);
      next if($errcount <= 3);
    }
    die("Select error $nfound ($err)\n");
  } else {
    $errcount= 0;
  }

  ###############################
  # Message from the hardware (FHZ1000/WS3000/etc) via select or the Ready
  # Function. The latter ist needed for Windows, where USB devices are not
  # reported by select, but is used by unix too, to check if the device is
  # attached again.

Code Auswählen Erweitern

# handle device not sending data until a timeout defined by the device module
$acttime = gettimeofday();

foreach my $p (keys %selectlist) {
    my $hash = $selectlist{$p};
    my $isDev = ($hash && $hash->{NAME} && $defs{$hash->{NAME}});
    my $isDirect = ($hash && ($hash->{directReadFn} || $hash->{directWriteFn}));
    next if(!$isDev && !$isDirect);

    if(defined($hash->{FD}) && vec($rout, $hash->{FD}, 1)) {

Code Auswählen Erweitern

# handle device not sending data until a timeout defined by the device module
if(defined($hash->{LastReadTimeout}))
{
# do ReadFn statistics
if(defined($hash->{LastReadTime}))
{
my $td = $acttime - $hash->{LastReadTime};
my $mean = $hash->{LastReadTDmean} * $hash->{LastReadTDN};
$hash->{LastReadTDN}++;
if ($hash->{LastReadTDN} > 0)
{
$mean /= $hash->{LastReadTDN};
$mean += $td / $hash->{LastReadTDN};
$hash->{LastReadTDmean} = $mean;
}
else
{
$hash->{LastReadTDN} = 0;
}
$hash->{LastReadTD} = $td;
$hash->{LastReadTDmax} = $td if($td > $hash->{LastReadTDmax});
}
# set last ReadFn time stamp
$hash->{LastReadTime} = $acttime;
}

if($hash->{directReadFn}) {
        $hash->{directReadFn}($hash);
      } else {
        CallFn($hash->{NAME}, "ReadFn", $hash);
      }
    }

    if((defined($hash->{$wbName}) || defined($hash->{directWriteFn})) &&
        defined($hash->{FD}) && vec($wout, $hash->{FD}, 1)) {

      if($hash->{directWriteFn}) {
        $hash->{directWriteFn}($hash);

      } else {
        my $wb = $hash->{$wbName};
        my $ret = syswrite($hash->{CD}, $wb);
        if(!$ret || $ret < 0) {
          Log 4, "Write error to $p, deleting $hash->{NAME}";
          TcpServer_Close($hash);
          CommandDelete(undef, $hash->{NAME});
        } else {
          if($ret == length($wb)) {
            delete($hash->{$wbName});
            if($hash->{WBCallback}) {
              no strict "refs";
              my $ret = &{$hash->{WBCallback}}($hash);
              use strict "refs";
              delete $hash->{WBCallback};
            }
          } else {
            $hash->{$wbName} = substr($wb, $ret);
          }
        }
      }
    }

    if(defined($hash->{"EXCEPT_FD"}) && vec($eout, $hash->{EXCEPT_FD}, 1)) {
      CallFn($hash->{NAME}, "ExceptFn", $hash);
    }
  }

  foreach my $p (keys %readyfnlist) {
    next if(!$readyfnlist{$p});                 # due to rereadcfg / delete

    if(CallFn($readyfnlist{$p}{NAME}, "ReadyFn", $readyfnlist{$p})) {
      if($readyfnlist{$p}) {                    # delete itself inside ReadyFn
        CallFn($readyfnlist{$p}{NAME}, "ReadFn", $readyfnlist{$p});
      }

    }
  }

}

Damit kann ich nun leicht Verbesserungen durch Hard- oder Softwareänderungen feststellen, ohne mühsam Sensor-Logs durchforsten zu müssen.

Immerhin hat der Timeout beim CUL schon einmal angesprochen, die dargestellte CUL_ReadTimeoutFn aufgerufen und schwubs kamen wieder Daten rein, wie erwartet. Ich hoffe, das bestätigt sich weiter so.

Ich werde berichten, wenn ich zu neuen Erkenntnissen zur Problemursache bei RasPi oder CUL komme und würde mich natürlich weiterhin über sachdienliche Hinweise zu diesen Aussetzern freuen.

Sollte die Codeergänzung nicht Deine Zustimmung finden, dann kannst Du den Thread auch gerne in Codeschnipsel verschieben.


Grüße und Danke für Deine Anregungen und den Wink zu watchdog, den ich jetzt anderweitig gerne nutze,

Ansgar.

[rudolfkoenig]

- ich bin unsicher, ob ich deine Zitat/Kommentar Paare richtig lese, ausserdem ist das Format extrem unpraktisch. Fuer Aenderungen im Code gibt es seit ueber 30 Jahren etablierte Methoden (diff -u/patch).
- den Sinn einer ReadTimeoutFn Funktion vertehe ich nicht. Lesen in FHEM laeuft doch ueber select(), sollte also nie Blockieren -> Timeout ist sinnlos.
- Statistikinformationen gehoeren mAn nicht in fhem.pl, man kann sowas gut mit Modulen erledigen, wie das apptime Modul von Martin beweist.

[noansi]

Hallo Rudolf,

hier mal die diff Variante. Nur die relevanten Änderungen sind drin, da ich ja in der Version schon hinterher hänge:

Code Auswählen Erweitern

30c30
< # $Id: fhem.pl 5663 2014-04-26 09:13:54Z rudolfkoenig $
---
> # $Id: fhem.pl 5728 2014-05-03 09:41:12Z rudolfkoenig $
519,521d524
< # handle device not sending data until a timeout defined by the device module
< my $acttime = gettimeofday();
<
524,577d526
<
< # handle device not sending data until a timeout defined by the device module
< # shows also a little statistics for execution of the device ReadFn
< #
< # in device module do
< # define $hash->{LastReadTimeout} with the read timeout in seconds
< # define $hash->{ReadTimeoutFn} with the reference to the handler function for read timeouts
< #
< # example for CUL:
< #
< # add timeout function
< # sub CUL_ReadTimeoutFn($)
< # {
< # my ($hash) = @_;
< # my $name = $hash->{NAME};
< #
< # Log3 $name, 1, "CUL_ReadTimeoutFn: $name Read timeout seen on serial port";
< #
< # DevIo_Disconnected($hash);
< #
< # return undef;
< # }
< #
< # in CUL_Define function add
< # $hash->{ReadTimeoutFn} = \&CUL_ReadTimeoutFn;
< # $hash->{LastReadTimeout} = 300;  # 300 seconds timeout, resonable for e.g. Homematic TH Sensors which continously send data in about 2 minutes interval
< #
< # in CUL_Undef function add
< # delete($hash->{ReadTimeoutFn});
< # delete($hash->{LastReadTime});
< # delete($hash->{LastReadTimeout});
< # delete($hash->{LastReadTDmax});
< # delete($hash->{LastReadTDmean});
< # delete($hash->{LastReadTDN});
< # delete($hash->{LastReadTD});
< # delete($hash->{LastReadTimeoutDetected});
<
< if(defined($hash->{LastReadTimeout}))
< {
< if (defined($hash->{LastReadTime}))
< {
< # handle timeout of receiving data from device
< my $td = $acttime - $hash->{LastReadTime};
< if($td > $hash->{LastReadTimeout})
< {
< Log 1, "Try ReadTimeoutFn $hash->{NAME}";
< $hash->{LastReadTimeoutDetected}++;
< $hash->{ReadTimeoutFn}->($hash) if(defined($hash->{ReadTimeoutFn}));
< $hash->{LastReadTime} = $acttime; #needed, else timeout forever after timeout
< next;
< }
< }
< }
<
627,630d575
<
< # handle device not sending data until a timeout defined by the device module
< $acttime = gettimeofday();
<
638,664d582
<
< # handle device not sending data until a timeout defined by the device module
< if(defined($hash->{LastReadTimeout}))
< {
< # do ReadFn statistics
< if(defined($hash->{LastReadTime}))
< {
< my $td = $acttime - $hash->{LastReadTime};
< my $mean = $hash->{LastReadTDmean} * $hash->{LastReadTDN};
< $hash->{LastReadTDN}++;
< if ($hash->{LastReadTDN} > 0)
< {
< $mean /= $hash->{LastReadTDN};
< $mean += $td / $hash->{LastReadTDN};
< $hash->{LastReadTDmean} = $mean;
< }
< else
< {
< $hash->{LastReadTDN} = 0;
< }
< $hash->{LastReadTD} = $td;
< $hash->{LastReadTDmax} = $td if($td > $hash->{LastReadTDmax});
< }
< # set last ReadFn time stamp
< $hash->{LastReadTime} = $acttime;
< }
< 

Ich hatte es erst mit Farben im Code versucht, aber leider will Code nicht mit Farbe. Ob der Diff nun besser ist?

- ich bin leider kein diff/patch experte, also berichtige mich bitte, wenn ich eine wichtige Option nicht verwendet habe
- ich wollte die Ergänzungen irgendwie im Zusammenhang darstellen, damit direkt klar wird, was es bedeutet
- select timeout hilft in diesem Fall leider nicht. Der timeout bei select führt zum Blockieren von select bis was (von einem der gewählten Geräte) kommt oder der timeout abläuft. Wenn bis zum select timeout nichts von irgendeinem Gerät kommt, steht FHEM so lange. Ich halte es für keine gute Idee, FHEM für in diesem Fall 5 Minuten anzuhalten, wenn keine Daten kommen (ein Thread!).
- Wenn nichts kommt, wird ReadFn nicht aufgerufen. Auch keine andere Funktion. Also kann ich im CUL Modul nicht feststellen dass nichts kommt, höchstens über einen Timer in der ReadFn Funktion. Den kann ich aber nicht selektiv löschen (es werden immer alle Timer für einen Hash gelöscht), wenn doch was kommt (ReadFn wird aufgerufen), ohne alle laufenden CUL Timer mit ins Nirvana zu reißen
- Oder ein ständig pollender Timer im CUL Modul. Auch nicht fein und wehe es werden doch mal in einer zukünftigen Version die Timer gelöscht.
- in meinem Fall wird auch kein Fehler von select geliefert, ich kann auf nichts reagieren, weil einfach gar nichts passiert
- mir ist nicht klar, wie ich solch eine Timeout Funktionalität sinnvoll mit watchdog o.ae. ausserhalb von fhem.pl erreichen kann???
- so ist es allgemein nutzbar. Habe ich auch gleich für USBWX genutzt.
- klar kann man Timing Statistik auch anders ermitteln. Muss auch nicht sein. Ich brauche nur den Zeitstempel. Ich fand es halt praktisch so, weil direkt beim Gerät im Blick.

Gruß, Ansgar.

[noansi]

Hallo Rudolf,


hier noch eine Variante als Diff, die die funktionelle Anpassung in fhem.pl auf das notwendigste begrenzt und alles andere dem nutzenden Modul zuschiebt:

Code Auswählen Erweitern


30c30
< # $Id: fhem.pl 5663 2014-04-26 09:13:54Z rudolfkoenig $
---
> # $Id: fhem.pl 5728 2014-05-03 09:41:12Z rudolfkoenig $
519,521d524
< # handle device not sending data until a timeout defined by the device module
< my $acttime = gettimeofday();
<
524,599d526
<
< # handle device not sending data until a timeout defined by the device module
< # shows also a little statistics for execution of the device ReadFn
< #
< # in device module do
< # define $hash->{LastReadTimeout} with the read timeout in seconds
< # define $hash->{ReadTimeoutFn} with the reference to the handler function for read timeouts
< #
< # example for CUL:
< #
< # add timeout function
< # sub CUL_ReadTimeoutFn($)
< # {
< # my ($hash) = @_;
< # my $name = $hash->{NAME};
< #
< # $hash->{LastReadTimeoutDetected}++;
< # Log3 $name, 1, "CUL_ReadTimeoutFn: $name Read timeout seen on serial port";
< #
< # DevIo_Disconnected($hash);
< #
< # return undef;
< # }
< #
< # in CUL_Read function directly after "my ($hash) = @_;" add
< # # do ReadFn statistics
< # if(defined($hash->{LastReadTime}))
< # {
< # my $acttime = gettimeofday();
< # my $td = $acttime - $hash->{LastReadTime};
< # my $mean = $hash->{LastReadTDmean} * $hash->{LastReadTDN};
< # $hash->{LastReadTDN}++;
< # if ($hash->{LastReadTDN} > 0)
< # {
< # $mean /= $hash->{LastReadTDN};
< # $mean += $td / $hash->{LastReadTDN};
< # $hash->{LastReadTDmean} = $mean;
< # }
< # else
< # {
< # $hash->{LastReadTDN} = 0;
< # }
< # $hash->{LastReadTD} = $td;
< # $hash->{LastReadTDmax} = $td if($td > $hash->{LastReadTDmax});
< # }
< #
< # in CUL_Define function add
< # $hash->{ReadTimeoutFn} = \&CUL_ReadTimeoutFn;
< # $hash->{LastReadTimeout} = 300;  # 300 seconds timeout, resonable for e.g. Homematic TH Sensors which continously send data in about 2 minutes interval
< #
< # in CUL_Undef function add
< # delete($hash->{ReadTimeoutFn});
< # delete($hash->{LastReadTime});
< # delete($hash->{LastReadTimeout});
< # delete($hash->{LastReadTDmax});
< # delete($hash->{LastReadTDmean});
< # delete($hash->{LastReadTDN});
< # delete($hash->{LastReadTD});
< # delete($hash->{LastReadTimeoutDetected});
<
< if(defined($hash->{LastReadTimeout}))
< {
< if (defined($hash->{LastReadTime}))
< {
< # handle timeout of receiving data from device
< my $td = $acttime - $hash->{LastReadTime};
< if($td > $hash->{LastReadTimeout})
< {
< Log 1, "Try ReadTimeoutFn $hash->{NAME}";
< $hash->{ReadTimeoutFn}->($hash) if(defined($hash->{ReadTimeoutFn}));
< $hash->{LastReadTime} = $acttime; #needed, else timeout forever after timeout
< next;
< }
< }
< }
<
649,652d575
<
< # handle device not sending data until a timeout defined by the device module
< $acttime = gettimeofday();
<
665,672d587
<
< # handle device not sending data until a timeout defined by the device module
< if(defined($hash->{LastReadTimeout}))
< {
< # set last ReadFn time stamp
< $hash->{LastReadTime} = $acttime;
< }
< 


Man beachte, dass der Zeitstempel jetzt nach dem Aufruf der ReadFn Funktion genommen wird (und werden muss).

Läßt man übrigens die Definition der ReadTimoutFn im jeweiligen Modul weg, so kann man auch nur die Statistik nutzen.
Fehlt die Definition von LastReadTimeout, dann passiert gar nichts, sprich es ist ausgeschaltet.

Ich hoffe, so findet es Deine Zustimmung.


Gruß und Danke,

Ansgar.

[rudolfkoenig]

Das Format ist besser, aber patch sagt dazu immer noch "Only garbage was found in the patch input.", richtig waere es gewesen mit diff -u, wie ich es vorher geschrieben habe.

Aendert nichts an meinen anderen  Bemerkungen, und ich habe nicht vor die Aenderungenin fhem.pl zu integrieren. Bevor ein von FHEM ausgeloestes Disconnect irgendwelche Probleme loest, sollte der Anwender den Hardware austauschen: die wenigsten werden mit einem 50%-Empfang zufrieden sein, und ich will nichts supporten, was die Haelfte der Nachrichten wg. Hardware-Fehler verliert.

Uebrigens man kann beliebig viele Timer mit sowas wie InternalTimer($triggerTime, "FnName", {hash=>$hash}) setzen, falls der Modulautor sowas realisieren moechte.

[noansi]

Hallo Rudolf,

ups, entschuldige bitte, -u ist mir im Eifer des Gefechts durchgegangen. Hier nochmal zum Abschluss ein kompletter diff -u und bitte den Versionsunterschied beachten weil er anderes wieder in die Vergangenheit befördert und nur MAIN die Änderungen enthält:

Code Auswählen Erweitern

--- ./fhem.pl 2014-05-11 10:22:30.000000000 +0200
+++ ../fhem.pl 2014-05-11 14:25:17.718179139 +0200
@@ -27,7 +27,7 @@
#
#  Homepage:  http://fhem.de
#
-# $Id: fhem.pl 5728 2014-05-03 09:41:12Z rudolfkoenig $
+# $Id: fhem.pl 5663 2014-04-26 09:13:54Z rudolfkoenig $


use strict;
@@ -54,8 +54,6 @@
sub Dispatch($$$);
sub DoTrigger($$@);
sub EvalSpecials($%);
-sub FileRead($);
-sub FileWrite($@);
sub FmtDateTime($);
sub FmtTime($);
sub GetLogLevel(@);
@@ -154,10 +152,7 @@
sub cfgDB_ReadAll($);
sub cfgDB_SaveState;
sub cfgDB_SaveCfg;
-sub cfgDB_AttrRead($);
-sub cfgDB_ReadFile($);
-sub cfgDB_UpdateFile($);
-sub cfgDB_WriteFile($@);
+sub cfgDB_GlobalAttr;
sub cfgDB_svnId;

##################################################
@@ -216,7 +211,7 @@
                 "eventMap userReadings";
my $currcfgfile=""; # current config/include file
my $currlogfile; # logfile, without wildcards
-my $cvsid = '$Id: fhem.pl 5728 2014-05-03 09:41:12Z rudolfkoenig $';
+my $cvsid = '$Id: fhem.pl 5663 2014-04-26 09:13:54Z rudolfkoenig $';
my $duplidx=0;                  # helper for the above pool
my $evalSpecials;               # Used by EvalSpecials->AnalyzeCommand parameter passing
my $intAtCnt=0;
@@ -515,15 +510,93 @@
# Main Loop
sub MAIN {MAIN:};               #Dummy

-
my $errcount= 0;
while (1) {
   my ($rout,$rin, $wout,$win, $eout,$ein) = ('','', '','', '','');

   my $timeout = HandleTimeout();

+ # handle device not sending data until a timeout defined by the device module
+ my $acttime = gettimeofday();
+
   foreach my $p (keys %selectlist) {
     my $hash = $selectlist{$p};
+
+ # handle device not sending data until a timeout defined by the device module
+ # shows also a little statistics for execution of the device ReadFn
+ #
+ # in device module do
+ # define $hash->{LastReadTimeout} with the read timeout in seconds
+ # define $hash->{ReadTimeoutFn} with the reference to the handler function for read timeouts
+ #
+ # example for CUL:
+ #
+ # add timeout function
+ # sub CUL_ReadTimeoutFn($)
+ # {
+ # my ($hash) = @_;
+ # my $name = $hash->{NAME};
+ #
+ # $hash->{LastReadTimeoutDetected}++;
+ # Log3 $name, 1, "CUL_ReadTimeoutFn: $name Read timeout seen on serial port";
+ #
+ # DevIo_Disconnected($hash);
+ #
+ # return undef;
+ # }
+ #
+ # in CUL_Read function directly after "my ($hash) = @_;" add
+ # # do ReadFn statistics
+ # if(defined($hash->{LastReadTime}))
+ # {
+ # my $acttime = gettimeofday();
+ # my $td = $acttime - $hash->{LastReadTime};
+ # my $mean = $hash->{LastReadTDmean} * $hash->{LastReadTDN};
+ # $hash->{LastReadTDN}++;
+ # if ($hash->{LastReadTDN} > 0)
+ # {
+ # $mean /= $hash->{LastReadTDN};
+ # $mean += $td / $hash->{LastReadTDN};
+ # $hash->{LastReadTDmean} = $mean;
+ # }
+ # else
+ # {
+ # $hash->{LastReadTDN} = 0;
+ # }
+ # $hash->{LastReadTD} = $td;
+ # $hash->{LastReadTDmax} = $td if($td > $hash->{LastReadTDmax});
+ # }
+ #
+ # in CUL_Define function add
+ # $hash->{ReadTimeoutFn} = \&CUL_ReadTimeoutFn;
+ # $hash->{LastReadTimeout} = 300;  # 300 seconds timeout, resonable for e.g. Homematic TH Sensors which continously send data in about 2 minutes interval
+ #
+ # in CUL_Undef function add
+ # delete($hash->{ReadTimeoutFn});
+ # delete($hash->{LastReadTime});
+ # delete($hash->{LastReadTimeout});
+ # delete($hash->{LastReadTDmax});
+ # delete($hash->{LastReadTDmean});
+ # delete($hash->{LastReadTDN});
+ # delete($hash->{LastReadTD});
+ # delete($hash->{LastReadTimeoutDetected});
+
+ if(defined($hash->{LastReadTimeout}))
+ {
+ if (defined($hash->{LastReadTime}))
+ {
+ # handle timeout of receiving data from device
+ my $td = $acttime - $hash->{LastReadTime};
+ if($td > $hash->{LastReadTimeout})
+ {
+ Log 1, "$hash->{NAME} ReadFn timeout $hash->{LastReadTimeout}s reached. Trying ReadTimeoutFn...";
+ $hash->{ReadTimeoutFn}->($hash) if(defined($hash->{ReadTimeoutFn}));
+ $hash->{LastReadTime} = $acttime; #needed, else timeout forever after timeout
+ next;
+ }
+ }
+ }
+
     if(defined($hash->{FD})) {
       vec($rin, $hash->{FD}, 1) = 1
         if(!defined($hash->{directWriteFn}));
@@ -573,6 +646,10 @@
   # Function. The latter ist needed for Windows, where USB devices are not
   # reported by select, but is used by unix too, to check if the device is
   # attached again.
+
+ # handle device not sending data until a timeout defined by the device module
+ $acttime = gettimeofday();
+
   foreach my $p (keys %selectlist) {
     my $hash = $selectlist{$p};
     my $isDev = ($hash && $hash->{NAME} && $defs{$hash->{NAME}});
@@ -585,6 +662,14 @@
       } else {
         CallFn($hash->{NAME}, "ReadFn", $hash);
       }
+
+ # handle device not sending data until a timeout defined by the device module
+ if(defined($hash->{LastReadTimeout}))
+ {
+ # set last ReadFn time stamp
+ $hash->{LastReadTime} = $acttime;
+ }
+
     }

     if((defined($hash->{$wbName}) || defined($hash->{directWriteFn})) &&
@@ -1233,11 +1318,8 @@

   foreach my $d (sort keys %defs) {
     next if($defs{$d}{TEMPORARY});
-    if($defs{$d}{VOLATILE}) {
-      my $def = $defs{$d}{DEF};
-      $def =~ s/;/;;/g; # follow-on-for-timer at
-      print SFH "define $d $defs{$d}{TYPE} $def\n";
-    }
+    print SFH "define $d $defs{$d}{TYPE} $defs{$d}{DEF}\n"
+        if($defs{$d}{VOLATILE});

     my $val = $defs{$d}{STATE};
     if(defined($val) &&
@@ -1885,20 +1967,17 @@
     if($arg[1]) {
       foreach my $sdev (@list) { # Show a Hash-Entry or Reading for each device

-        if($defs{$sdev}) {
-          if($defs{$sdev}{$arg[1]}) {
-            $str .= sprintf("%-20s %s\n", $sdev, $defs{$sdev}{$arg[1]});
-
-          } elsif($defs{$sdev}{READINGS} &&
-                  $defs{$sdev}{READINGS}{$arg[1]}) {
-            $str .= sprintf("%-20s %s %s\n", $sdev,
-                    $defs{$sdev}{READINGS}{$arg[1]}{TIME},
-                    $defs{$sdev}{READINGS}{$arg[1]}{VAL});
-
-          } elsif($attr{$sdev} && $attr{$sdev}{$arg[1]}) {
-            $str .= sprintf("%-20s %s\n", $sdev, $attr{$sdev}{$arg[1]});
-
-          }
+        if($defs{$sdev} &&
+           $defs{$sdev}{$arg[1]}) {
+          $str .= $sdev . " " .
+                  $defs{$sdev}{$arg[1]} . "\n";
+
+        } elsif($defs{$sdev} &&
+           $defs{$sdev}{READINGS} &&
+           $defs{$sdev}{READINGS}{$arg[1]}) {
+          $str .= $sdev . " ".
+                  $defs{$sdev}{READINGS}{$arg[1]}{TIME} . " " .
+                  $defs{$sdev}{READINGS}{$arg[1]}{VAL} . "\n";
         }
       }

@@ -1935,6 +2014,7 @@
   $param =~ s,\.pm$,,g;
   my $file = "$attr{global}{modpath}/FHEM/$param.pm";
   my $cfgDB = '-';
+
   if( ! -r "$file" ) {
     if(configDBUsed()) {
       # try to find the file in configDB
@@ -2120,13 +2200,10 @@
     my $counter = 0;

     if(configDBUsed()) {
-      my $list = cfgDB_Read99(); # retrieve filelist from configDB
-      if($list) {
-        foreach my $m (split(/,/,$list)) {
-          $m =~ m/^([0-9][0-9])_(.*)\.pm$/;
-          CommandReload(undef, $m) if(!$modules{$2}{LOADED});
-          $counter++;
-        }
+      my @dbList = split(/,/,cfgDB_Read99()); # retrieve filelist from configDB
+      foreach my $m (@dbList) {
+        CommandReload(undef, $m);
+        $counter++;
       }
     }

@@ -3214,15 +3291,13 @@
{
   my ($f) = @_;

-  my ($err, @rows);
   if($f eq 'configDB') {
-    @rows = cfgDB_AttrRead('global');
-  } else {
-    ($err, @rows) = FileRead($f);
-    die("$err\n") if($err);
+    cfgDB_GlobalAttr();
+    return;
   }

-  foreach my $l (@rows) {
+  open(FH, $f) || die("Cant open $f: $!\n");
+  while(my $l = <FH>) {
     $l =~ s/[\r\n]//g;
     next if($l !~ m/^attr\s+global\s+([^\s]+)\s+(.*)$/);
     my ($n,$v) = ($1,$2);
@@ -3231,6 +3306,7 @@
     $attr{global}{$n} = $v;
     GlobalAttr("set", "global", $n, $v);
   }
+  close(FH);
}


@@ -3784,50 +3860,4 @@
   return ($attr{global}{configfile} eq 'configDB');
}

-sub
-FileRead($)
-{
-  my ($fname) = @_;
-  my ($err, @ret);
-
-  if(configDBUsed()) {
-    @ret = cfgDB_FileRead($fname);
-    $err = "$fname not found in the database." if(@ret==1 && !defined($ret[0]));
-
-  } else {
-    if(open(FH, $fname)) {
-      @ret = <FH>;
-      close(FH);
-    } else {
-      $err = "Can't open $fname: $!";
-    }
-  }
-
-  return ($err, @ret);
-}
-
-sub
-FileWrite($@)
-{
-  my ($fname, @rows) = @_;
-  my ($err, @ret);
-
-  if(configDBUsed()) {
-    return cfgDB_FileWrite($fname, @rows);
-
-  } else {
-    if(open(FH, ">$fname")) {
-      foreach my $l (@rows) {
-        print FH $l;
-      }
-      close(FH);
-      return undef;
-
-    } else {
-      return "Can't open $fname: $!";
-
-    }
-  }
-}
-
1;

Sei's drum, den Versuch war's wert.

Nochmal zum eigentlichen Thema, dem ich ja auf den Grund gehen will. Ich habe nun mal im PDF zum Transceiver gelesen und das State Register gefunden. Also etwas Ergänzung in meine Timeout Funktion liefert:

2014.05.11 21:33:11 1: CUL_0 ReadFn timeout 300s reached. Trying ReadTimeoutFn...
2014.05.11 21:33:11 1: CUL_ReadTimeoutFn: CUL_0 Read timeout no 1 seen on serial port, transeiver-state: get raw => C35 = 0D / 13
2014.05.11 21:33:11 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)
2014.05.11 21:33:11 1: /dev/ttyACM0 reappeared (CUL_0)

Also der Transceiver steht im Empfang, sieht also normal aus, denke ich. Das kommt auch wenn ich den Befehl auch so mal absetze.
Die USB-Verbindung geht offenbar auch noch, sonst wäre das Register nicht auslesbar gewesen.

Mit dem nächsten Timeout werde ich dann mit C99 mal mehr auslesen. Mal sehen, ob sich da noch was ergibt.
Wenn das bestellte dickere Netzteil da ist, bin ich mal gespannt, ob das des Rätsels Lösung bringt.

Gruß und Danke, Ansgar.

[noansi]

Hallo CUL Programmier Experten,


nun habe ich 3 Hänger am CUL, der nur auf Homematic läuft, mit geloggt und jeweils ein get raw C99 vor dem disconnect abgesetzt um die Transceiver Register auszulesen:

2014.05.12 05:36:18 1: CUL_ReadTimeoutFn: CUL_0 Read timeout no 1 seen on serial port, transeiver-state: get uptime => 7 15:45:26, get raw => C35 = 0D / 13, get raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AF2A3F114100597F3E81350B00

2014.05.12 11:40:55 1: CUL_ReadTimeoutFn: transeiver-state: get uptime => 7 21:50:03, get raw => C35 = 0D / 13, get raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AF2A3F114100597F3E81350B00

2014.05.12 20:16:39 1: CUL_ReadTimeoutFn: transeiver-state: get uptime => 8 06:25:49, get raw => C35 = 0D / 13, get raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AF2A3F114100597F3E81350B00

Wenn ich einfach so im Normalbetrieb mal get raw C99 teste bekomme ich:

CUL_0 raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AC2A15114100597F3E81350B00

Der Unterschied liegt in in den Registern 0x23 und 0x25, FSCAL3 und FSCAL1.

Normal ist 0x23 auf 0xAC und im hängenden Fall auf AF.
Normal ist 0x25 auf 0x15 und im hängenden Fall auf 3F.

Eingestellt ist der Transceiver auf FS_AUTOCAL 01 -> When going from IDLE to RX or TX (or FSTXON) laut Doku CC1101.

Sagt jemandem das spontan was?

Die Chip Doku sagt dazu noch:

As an alternative the user can read register FSCAL1. The PLL is in lock if the register content is different from 0x3F. Refer also to  the  CC1101 Errata Notes  [3]

Wenn ich nichts unternehme, also keinen Disconnect oder harten Reset, dann kommt nach längerer Zeit (bis zu 2 Stunden) wieder was an Daten rein, warum auch immer. Außerdem kann ich nichts senden, Komandos kommen nicht bei Empfängern an.

Ich werde nun versuchen, noch am Ende von in CUL_DoInit die Register auszulesen. Mal schauen, was dann drin steht.


Gruß und Danke, Ansgar.

[noansi]

Hallo CUL Programmier Experten,

nun das Ergebnis des Loggens vor und nach dem Disconnect:

Code Auswählen Erweitern

2014.05.13 11:32:28 1: CUL_0 ReadFn timeout 300s reached. Trying ReadTimeoutFn...
2014.05.13 11:32:28 1: CUL_ReadTimeoutFn: CUL_0 Read timeout no 1 seen on serial port
2014.05.13 11:32:28 1: CUL_ReadTimeoutFn: transeiver-state: get uptime => 8 21:41:40, get raw => C35 = 0D / 13, get raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AF2A3F114100597F3E81350B00
2014.05.13 11:32:28 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)
2014.05.13 11:32:29 1: /dev/ttyACM0 reappeared (CUL_0)
2014.05.13 11:32:30 1: CUL_DoInit: transeiver-state: get uptime => 8 21:41:41, get raw => C35 = 0D / 13, get raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AC2A15114100597F3E81350B00

Der Transceiver zeigt danach wieder die gleichen Registerwerte, wie im Normalzustand.

Wird beim erneuten Öffnen der Schnittstelle der Transceiver neu initialisiert und erholt sich dadurch wieder?
Bedeutet das, das der CUL eine Macke hat?

Kann der Transceiver durcheinander und außer Tritt kommen, wenn in der Umgebung auch noch SlowRF Geräte auf (fast) gleicher Frequenz senden?

Den RasPi kann ich nun wohl als Ursache ausschließen, denke ich.

Der Test mit der Stromversorgung steht noch aus. Darauf hoffe ich nun noch.

Kann ich noch was sinnvolles loggen, was mehr Klarheit bringen kann?

Gruß und Danke,

Ansgar.

[rudolfkoenig]

Wird beim erneuten Öffnen der Schnittstelle der Transceiver neu initialisiert und erholt sich dadurch wieder?

Ja, evtl.

Bedeutet das, das der CUL eine Macke hat?

Evtl.

Kann der Transceiver durcheinander und außer Tritt kommen, wenn in der Umgebung auch noch SlowRF Geräte auf (fast) gleicher Frequenz senden?

Eigentlich nicht, beobachtet hat das noch keiner.

Den RasPi kann ich nun wohl als Ursache ausschließen, denke ich.

Und worauf genau beruht diese Behauptung?

Kann ich noch was sinnvolles loggen, was mehr Klarheit bringen kann?

Ja, wie ich schon mal geschrieben habe, das Ding an einem "richtigen" Rechner (d.h. mir ordentlichen Stromversorgung) ausprobieren. Aber soweit ich es bisher gesehen habe, bist Du eher einer, der nicht Ratschlaege sucht, sondern die eigenen Theorien bestaetigen moechte. Ist auch nicht verkehrt, gute Forscher hoeren nicht auf die anderen, kann aber die Ratgebenden etwas nerven.

[noansi]

Hallo Rudolf,

erst mal vielen Dank für alle Deine Antworten und Deine Mühe, anderen und mir zu helfen. Und besten Dank für die viele Arbeit, Du in das FHEM Projekt sowohl mit Programmierung, als auch Support steckst und gesteckt hast. Nerven möchte ich keineswegs.
Deine Anregungen nehme ich durchaus ernst und teste sie durch, Netzteile sind auch gekommen. Der Test startet am Wochenende.
Es ist schlicht so, dass ich den Hardwaretest distanzbdingt nur mit Verzögerung durchführen kann, aber Remote wunderbar schon Softwaremöglichkeiten ausloten kann. Und mein Gefühl dabei schließt ein selten auftretendes Softwareproblem nicht aus, auch wegen der Systematik, siehe unten.
Eigentlich möchte ich nur zuverlässig die Sensoren empfangen können, um auf die Temperatursignale regeln zu können und nicht regelmäßig in die Hardwarebegrenzung rennen, weil z.B. die letzte empfangene Temperatur unter dem Sollwert hängen bleibt oder umgekehrt nicht geheizt wird weil sie drüber hängen bleibt.

Mit den Änderungen, die ich vorgenommen habe, kann ich jetzt auch schon einges sehen. So kann ich sagen, dass, ohne die Timeouts zu berücksichtigen, maximal alle 80s Daten vom CUL und somit von irgend einem der Sensoren kommen. Im Mittel kommen alle 12s Daten vom CUL rein.

Mittlerweile habe ich im Dauerbetrieb von 3 Tagen 11x meinen 5 Minuten Timeout geloggt und jeweils jedes mal den gleichen schon beschriebenen Registerzustand vorher und nacher gesehen.

Und worauf genau beruht diese Behauptung?

In allen Fällen des Timeouts konnte ich beim CUL die Register vor dem Disconnect anfordern und habe eine Antwort bekommen, ohne dass die Schnittstelle neu geöffnet worden wäre. Damit steht offenbar die USB Verbindung vom RasPi zum CUL noch in beide Richtungen und es kommen nur keine Empfangsdaten von den Sensoren rein. Der RasPi ist mir auch noch nie abgestürzt und seine Logs sind bezüglich USB sauber. Daher setze ich auch meine erste Hardwarehoffnung auf das Netzteil, das nach allen Recherchen dazu mit 1A etwas knapp bemessen ist. Die Spannung werd ich auch noch am CUL messen, um da Klarheit zu bekommen.

Ich habe auch noch das cc1101 Errata swrz020d.pdf gefunden und darin wird auch die Möglichkeit eines Empfangshängers beschrieben:

RXFIFO_OVERFLOW Issue Radio stays in RX state instead of entering RXFIFO_OVERFLOW state ...

Und noch einen weiteren Abschnitt zum FSCAL1 Register:

PLL Lock Detector Output PLL lock detector output is not 100% reliable

PLL lock can be checked reliably as follows:
1...
2. Read register FSCAL1. The PLL is in lock if the register content is different from
0x3F. With both of the above workarounds, the CC1101 PLL calibration should be
carried out with the correct settings for TEST0.VCO_SEL_CAL_EN and
FSCAL2.VCO_CORE_H_EN. These settings are depending on the operating
frequency, and is calculated automatically by SmartRF™ Studio. It must be noted
that the TEST0 register content is not retained in SLEEP state, and thus it is
necessary to write to this register as described above when returning from the
SLEEP state.

Ob der CUL mit seiner Programmierung für so einen beschrieben Empfangshänger anfällig sein kann, versuche ich am Quelltext zu ergründen, wenn die Hardwaretests nichts bringen.
Den 0x3F Zustand von FSCAL1 sehe ich bei jedem der Timeouts, jedoch nicht bei Abfrage der Register ohne Timeout.

Danke und Gruß, Ansgar.

[Jens_B]

Für mich sieht das nach einem Hardware Problem aus. -> defektes cul, falsches Netzteil am Pi, oder defekt. Je nachdem was noch am USB Port dran ist kann das schon zu Problemen führen.
Hängt der cul den direkt am Pi oder über einen USB hub?

Schon mal das cul auf anderer Hardware unter fhem probiert?

Ich persönlich hätte nicht lange gefackelt und ein anderes Netzteil und ein andres cul probiert....

Gruß
Jens


Gesendet von meinem iPhone mit Tapatalk

[noansi]

Hallo CUL Programmier Experten,


@Jens: Vielen Dank für Deine Antwort. Der CUL hängt, ebenso wie mein USB-WDE1, mit USB Verlängerungskabel direkt am RasPi. Den RasPi bediene ich nur über Netzwerk, also ohne Tastaur, Maus und Monitor.
Das Zwangs-Fackeln hat ein Ende.

Hier die bisherigen Ergebnisse des Hardware Tauschs.

1A Netzteil gegen 2A Netzteil getauscht: Timeouts, wie gehabt.

Zusätzlich RasPi gegen Reserve RasPi getauscht: Timeouts, wie gehabt.

Zusätzlich USB Verbindungskabel gegen 3m Kabel mit 2 Ferritkernen getauscht (von busware mit CUL bezogen): Timeouts, wie gehabt. Spannung am CUL stabil bei 4,95V

Nun habe ich einen weiteren CUL geordert und zusätzlich noch einen COC und werde berichten, wenn ich damit getestet habe.

En PC-Test muss aus Zeitgründen noch warten.


Gruß, Ansgar.

PS: Wenn mal ein CUL Nutzer mit einigen Homematic Temperatur-Sensoren (ich habe 14 im Einsatz, mit RSSI von -48 bis -89) meine paar Code Änderungen in fhem.pl und CUL.pm einbauen und auch mal testen könnte, würde das vielleicht ebenfalls weiter helfen. Statt 300s Timeout meinetwegen auch 600s, damit schlechte Empfangsverhältnisse das Ergebnis nicht verfälschen.

[Jens_B]

Also ich weiß ja nicht wieviel Strom der cul benötigt, aber beides an direkt an die raspi Ports zu hangen( die beide am soeben Bus hangen, das heißt zusammen nur max 500 mA Strom liefern... )
Kann auch schon problematisch sein. Ich würde stromhungrige Geräte welche keine eigene Stromversorgung am Pi nur über eine aktiven USB Hub betreiben.
Gruß
Jens


Gesendet von meinem iPhone mit Tapatalk

[noansi]

Hallo Jens,

nun, so weit ich heraus finden konnte, liegt der Strom für den CUL unter 100mA (so meldet er sich laut CUL Quelltext auch als USB Gerät an, wenn ich das nicht missverstanden habe). Ebenso, wie der Strom für den USB-WDE1 unter 100mA liegt. Also beide keine stromkritischen USB Geräte. Der RasPi B liegt bei 700mA. Somit sollte auch schon das 1A Netzteil dafür reichen. Mit dem 2A Netzteil bin ich auf der sicheren Seite (es wird auch nicht warm). Und da die Spannung am CUL gemessen ebenfalls gut aussieht, sehe ich hier elektrisch derzeit kein Problem.

Ich habe einen interessanten Logeintrag:

Code Auswählen Erweitern

2014.05.18 23:54:32 1: CUL_0 ReadFn timeout 300s reached. Trying ReadTimeoutFn...
2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13


2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13


2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04


2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A


2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700


2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

2014.05.18 23:54:32 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B


2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41


2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00

2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00


2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00

C35 = 0D / 13

2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00

C35 = 0D / 13


2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00

C35 = 0D / 13

? (0D280597F8788310B35 = 0D / 13 is unknown) Use one of B C F i A Z E G M K U R T V W X e f m l t u x

2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00

C35 = 0D / 13

? (0D280597F8788310B35 = 0D / 13 is unknown) Use one of B C F i A Z E G M K U R T V W X e f m l t u x


2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00

C35 = 0D / 13

? (0D280597F8788310B35 = 0D / 13 is unknown) Use one of B C F i A Z E G M K U R T V W X e f m l t u x

0015ABD7

2014.05.18 23:54:33 2: CUL_0: unknown message C35 = 0D / 13

C35 = 0D / 13

0D2E2D07D3913D04

320000060021656A

55E43023B9000700

18146C070090876B

F85611EF2A151F41

00597F8788310B00

C35 = 0D / 13

? (0D280597F8788310B35 = 0D / 13 is unknown) Use one of B C F i A Z E G M K U R T V W X e f m l t u x

0015ABD7


2014.05.18 23:54:36 1: /dev/ttyACM0 disconnected, waiting to reappear (CUL_0)
2014.05.18 23:54:36 1: CUL_ReadTimeoutFn: CUL_0 Read timeout no 2 seen on serial port
2014.05.18 23:54:36 1: CUL_ReadTimeoutFn: transeiver-state: get uptime => No answer, get raw => C35 = 0D / 13, get raw => C35 = 0D / 13
2014.05.18 23:54:36 1: /dev/ttyACM0 reappeared (CUL_0)
2014.05.18 23:54:36 1: CUL_DoInit: transeiver-state: get uptime => 0 03:09:26, get raw => C35 = 0D / 13, get raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AC2A15114100597F3E81350B00


Die Registerabfrage vor dem Disconnect ist da irgendwie merkwürdig durcheinander geraten.


Gruß, Ansgar.

[noansi]

Hallo Rudolf und alle anderen CUL Programmier Experten,


da der neue CUL noch nicht zu Testzwecken eingetroffen ist, habe ich mal einen Blick in den CUL Firmware Sourcecode und auch die CC1101 Doku geworfen.

Die Doku sagt:

The PLL is in lock if the register content is different from 0x3F. Refer also to the CC1101 Errata Notes [3]. The PLL must be re-calibrated until PLL lock is achieved if the PLL does not lock the first time.
If the calibration is not performed each time before entering active mode (RX or TX)  the user  should  program register IOCFGx.GDOx_CFG  to 0x0A to check that the PLL is in lock before receiving/transmitting data.

Eine solche Prüfung habe ich in rf_asksin.c nicht gefunden (nur ein Kalibrierung bei der Initialisierung) und die Prüfung mal eingebaut, mitsamt Debugausgabe "PLLNOLOCK" und einer Kalibrierung im Falle fehlenden PLL Locks (falls Register CC1100_FSCAL1 == 0x3f). Den Wert hatte ich ja zuvor in meinen Log Ausgaben jedes mal im Register CC1100_FSCAL1 gesehen.

Die neue Logausgabe taucht nun auch (selten, wie zuvor auch die Aussetzer,) auf:

2014.05.25 18:48:02 2: CUL_0: unknown message PLLNOLOCK
2014.05.25 20:39:45 2: CUL_0: unknown message PLLNOLOCK

und danach (hoffentlich wegen der ausgeführten Kalibrierung) sind auch brav weiter Daten gekommen. Muss ich noch was beobachten, denke aber auf dem richtigen Weg zu sein.

Zumindest hatte der CC1101 im bisherigen Code eine Chance zur Selbsterholung, da FS_AUTOCAL auf 1 steht und damit beim Wechsel von IDLE nach TX oder RX eine automatische Kalibrierung durchgeführt würde. Wie der Zustandswechsel so zustande kommt und damit zur Selbstheilung (nach bis zu 2 Stunden) geführt haben könnte, habe ich jedoch noch nicht gesehen?

Warum der CC1101 die Kalibrierung verliert kann ich nicht sagen und bin mal gespannt, ob der neue CUL das genauso macht.

Eine zuvor genutzte Methode, im Falle fehlenden PLL Locks beim State MARCSTATE_RX einfach mal rf_asksin_init aufzurufen hat jedenfalls schon mal den Empfang erhalten (mein Timeout in fhem.pl löst damit nicht aus), kostet aber mehr Zeit.

Was ich am rf_asksin.c Code noch nicht verstehe, ist die Stateumschaltung. Zum einen ohne Timeout zur Prüfung auf den Ziel-State-Zustand (TX/RX) und zum Teil ohne Prüfung, ob der State auch eingenommen wurde oder einfach mit Wartezeiten?
Dient das der Ersparnis von Programmspeicherplatz mit (empirisch ?) ermittelten Warte- und Schaltzeiten?


Gruß, Ansgar.

[rudolfkoenig]

Ich meine auch, dass due auf dem richtigen Weg bist, leider kann ich deine Frage nicht beantworten, vielleicht einer der Co-Autoren von rf_asksin.c

[noansi]

Hallo CUL rf_asksin Programmier Experten,


das bisherige Testergebnis der Kalibrierung bei fehlendem PLL Lock sieht gut as.

Zwei mal wurde der fehlende PLL Lock bisher noch aufgezeichnet und der Empfangstimeout ist nicht mehr aufgreten und auch die Sensorkurven sehen sauber aus:

2014.05.26 14:45:06 2: CUL_0: unknown message PLLNOLOCK
2014.05.26 23:08:03 2: CUL_0: unknown message PLLNOLOCK

Ob die Sendeprobleme damit auch gelöst sind, werde ich am Wochendende testen, ebenso die Vergleichs-Hardware, die heute eingetroffen ist.

@Rudolf: Danke für Deine Antwort und den Vesuch. Wäre eine Codeänderung in dieser Richtung in der CUL Firmware ein Update wert? Blöderweise kann ich es nur bei CUL V3.4 und künftig bei COC V1.2 testen und weiß auch nicht, wie eng es bei den anderen im Speicher aussieht?

Wäre nett, wenn noch jemand zu meinen Code Fragen was schreiben könnte. Ich würde gern unnötige Bytes sparen, wo der bisherige Code auf Erkennissen aus der CC1101 Doku beruht.


Gruß, Ansgar.

[rudolfkoenig]

Wäre eine Codeänderung in dieser Richtung in der CUL Firmware ein Update wert?

Sicher, ich haette nur gerne noch feedback von einem weiteren Benutzer mit viel HM Hardware.
Evtl. in der HM Gruppe nachfragen.

und weiß auch nicht, wie eng es bei den anderen im Speicher aussieht?

Ein CUL_V2 hat 16k Flash, die anderen CULs 32k. Davon kommen 4k Bootloader + 4k USB Bibliothek (LUFA) weg.
V2 mit SlowRF ist extrem eng am Speicher (12 Bytes frei, siehe make size), fuer HM und MAX muessen andere Binaries verwendet werden. Diese Versionen haben dann jeweils etwa 1K Platz fuer Code frei. Die anderen Modelle haben Platz genug (CUL_V3: 10k frei, COC: 100k frei): du brauchst vermutlich keine Sorgen wg. Speicher zu machen.

[tpm88]

Sicher, ich haette nur gerne noch feedback von einem weiteren Benutzer mit viel HM Hardware.

Hallo Ansgar, Rudi,

ich lese das Thema schon eine Weile mit Interesse mit - ich beobachte ähnliche Phänomene bei meinem CULv3 an einer FB7390. Gelegentlich meldet der ActionDetector alle meine vier RT-DN HM Thermostate als dead - nach einiger Zeit (wenige Stunden) funktionieren sie plötzlich wieder.

Code Auswählen Erweitern


2014-05-17_16:56:51 ActionDetector alive:4 dead:0 unkn:0 off:0
2014-05-20_03:37:23 ActionDetector status_dg_Thermostat: dead
2014-05-20_03:37:23 ActionDetector status_az_Thermostat: dead
2014-05-20_03:37:23 ActionDetector status_wz_Thermostat: dead
2014-05-20_03:37:23 ActionDetector status_bd_Thermostat: dead
2014-05-20_03:37:23 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-20_04:27:24 ActionDetector status_dg_Thermostat: alive
2014-05-20_04:27:24 ActionDetector status_az_Thermostat: alive
2014-05-20_04:27:24 ActionDetector status_wz_Thermostat: alive
2014-05-20_04:27:24 ActionDetector status_bd_Thermostat: alive
2014-05-20_04:27:24 ActionDetector alive:4 dead:0 unkn:0 off:0
2014-05-20_19:57:32 ActionDetector status_dg_Thermostat: dead
2014-05-20_19:57:32 ActionDetector status_az_Thermostat: dead
2014-05-20_19:57:32 ActionDetector status_wz_Thermostat: dead
2014-05-20_19:57:32 ActionDetector status_bd_Thermostat: dead
2014-05-20_19:57:32 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-21_06:47:47 ActionDetector status_dg_Thermostat: alive
2014-05-21_06:47:47 ActionDetector status_az_Thermostat: alive
2014-05-21_06:47:47 ActionDetector status_bd_Thermostat: alive
2014-05-21_06:47:47 ActionDetector alive:3 dead:1 unkn:0 off:0
2014-05-21_06:57:47 ActionDetector status_wz_Thermostat: alive
2014-05-21_06:57:47 ActionDetector alive:4 dead:0 unkn:0 off:0


Dazu zeitlich passend habe ich einen Sendefehler am 21.05. um 05:30 Uhr - hier wird die Heizungspumpe via HM aktiviert:

Code Auswählen Erweitern

2014-05-21_05:30:00 ke_Pumpe set_on-for-timer 5400
2014-05-21_05:30:15 ke_Pumpe ResndFail
2014-05-21_05:30:15 ke_Pumpe MISSING ACK


Bin gerne bereit, hier ggf. mit einer geänderten CUL FW zu testen.

Gruss
Tobias

[noansi]

Hallo Rudolf, hallo Tobias,


ok, dann hier die Codeänderungen. Ich möchte es noch beta nennen, da sicherlich noch optimierbar. Für TX, also Senderichtung habe ich es auch gleich eingebaut. Vielleicht kann Martin das Timingtechnisch nochmal für den Normalfall, also ohne PLL Lock Problem, mal gegen checken.


Mit

attr CUL_0 verbose 2

für den CUL (CUL_0 ggf. anpassen) werden die eingebauten Meldungen ins Log geschrieben.

Ausgegeben werden:
PLLERR , wenn der Registerzustand aus meinen Logs im RX State erkannt wird und aufgrund dessen rf_asksin_init aufgerufen wird (die harte Methode, da damit auch SRES ausgeführt wird).
PLLNOLOCK , wenn der CUL ohne PLL Lock erwischt wird. Dann wird die Kalibrierung versucht.
PLLLOCKFAIL , wenn mehrere Versuche des Kalibrierens nicht zu einem erfolgreichen PLL Lock führen.


@Rudolf: Danke für den Speicherhinweis! Wäre schön, wenn Du das Speichertechnisch für CUL_V2 mal checken könntest. Die Ausgaben zu size verstehe ich noch nicht ganz und möchte nicht fehlinterpretieren.

@Tobias: Danke für Deine Problemnachricht. Zur Fritz!Box 7390 darf ich aus eigener Erfahrung sagen, dass die USB Stromversorgung da auch eine Rolle spielen kann (siehe auch Rudolfs und Jens Tipps und Hinweise zur Stromversorgung), zumindest mit USB-Sticks (CUL war noch nie daran angeschlossen) hatte ich da Probleme, die sich mit einem dickeren Netzteil beheben ließen. Das original Netzteil hatte das auch anfangs mit gemacht aber ist dann nach ca. 1 Jahr Betrieb etwas eingebrochen. Wenn Du also mehr als nur den CUL daran hängen hast, dann kann die Stromversorgung auch Problemursache sein.
Wenn Du nicht gerade einen CUL_V2 (und damit eventuell zu wenig Programmspeicherplatz) hasst, dann würde ich mich freuen, von Deinen Erfahrungen mit der Firmwareänderung zu lesen. Bitte auch den verbose Modus für den CUL auf 2 setzen, damit es im Log auch sichtbar wird.


Hier der diff zu rf_asksin.c:

Code Auswählen Erweitern

--- rf_asksin.c 2014-03-13 21:49:42.000000000 +0100
+++ clib/rf_asksin.c 2014-05-27 23:03:27.896030622 +0200
@@ -58,6 +58,10 @@
#endif

static void rf_asksin_reset_rx(void);
+static void rf_asksin_toRX(void);
+static void rf_asksin_toTX(void);
+static uint8_t asksin_checkPLL(void);  // noansi: returns 0 on success
+

void
rf_asksin_init(void)
@@ -90,24 +94,26 @@
     }
   }
#endif
- 
+
   ccStrobe( CC1100_SCAL );

   my_delay_ms(4);

   // enable RX, but don't enable the interrupt
-  do {
-    ccStrobe(CC1100_SRX);
-  } while (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_RX);
+ // noansi: check PLL is in Lock in RX
+ rf_asksin_toRX();
}

+
static void
rf_asksin_reset_rx(void)
{
+  ccStrobe( CC1100_SIDLE ); // noansi: if stuck in RX after RX OVERFLOW as described in CC1101 errata -> do SFRX only in IDLE as CC1101 doc
   ccStrobe( CC1100_SFRX  );
-  ccStrobe( CC1100_SIDLE );
-  ccStrobe( CC1100_SNOP  );
-  ccStrobe( CC1100_SRX   );
+  //ccStrobe( CC1100_SIDLE );
+  //ccStrobe( CC1100_SNOP  );
+  //ccStrobe( CC1100_SRX   );
+ rf_asksin_toRX(); // noansi: try to set RX with calibration
}

void
@@ -143,9 +149,7 @@

     CC1100_DEASSERT;

-    do {
-      ccStrobe(CC1100_SRX);
-    } while (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_RX);
+    rf_asksin_toRX();

     last_enc = msg[1];
     msg[1] = (~msg[1]) ^ 0x89;
@@ -178,14 +182,33 @@
   }

   switch(cc1100_readReg( CC1100_MARCSTATE )) {
+    case MARCSTATE_RX:
+ // noansi: try init, if stuck in RX State with no PLL Lock as seen in extended read timeout logging
+ l = cc1100_readReg( CC1100_FSCAL1 );
+ if (l == 0x3f) { // noansi: no PLL Lock as described in CC1101 errata
+ l = cc1100_readReg( CC1100_FSCAL3 );
+ if (l == 0xaf) { // noansi: saw this too, if no data is received any more for a long period of time (up to 2 hours)
+ DS_P(PSTR("PLLERR\r\n"));
+ rf_asksin_init(); // noansi: try init to recover
+ return;
+ }
+ }
+ break;
     case MARCSTATE_RXFIFO_OVERFLOW:
+      ccStrobe( CC1100_SIDLE ); // noansi: if stuck in RX after RX OVERFLOW as described in CC1101 errata -> do SFRX only in IDLE as CC1101 doc
       ccStrobe( CC1100_SFRX  );
     case MARCSTATE_IDLE:
-      ccStrobe( CC1100_SIDLE );
-      ccStrobe( CC1100_SNOP  );
-      ccStrobe( CC1100_SRX   );
+      //ccStrobe( CC1100_SIDLE );
+      //ccStrobe( CC1100_SNOP  );
+      //ccStrobe( CC1100_SRX   );
+ rf_asksin_toRX(); // noansi: try to set RX with calibration
       break;
   }
+
+ if (asksin_checkPLL()) // noansi: check PLL is in Lock
+ {
+ rf_asksin_toRX(); // noansi: try to set RX with calibration
+ }
}

void
@@ -218,10 +241,8 @@
   
   msg[l] = msg[l] ^ ctl;

-  // enable TX, wait for CCA
-  do {
-    ccStrobe(CC1100_STX);
-  } while (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_TX);
+ // noansi: set TX with check/try PLL is in Lock in TX
+ rf_asksin_toTX();

   if (ctl & (1 << 4)) { // BURST-bit set?
     // According to ELV, devices get activated every 300ms, so send burst for 360ms
@@ -252,14 +273,118 @@
   }
   
   if(asksin_on) {
-    do {
-      ccStrobe(CC1100_SRX);
-    } while (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_RX);
+ // noansi: set RX with check/try PLL is in Lock in RX
+ rf_asksin_toRX();
   } else {
     set_txrestore();
   }
}

+static void
+rf_asksin_toRX(void)
+{
+ uint8_t n;
+ uint8_t t;
+
+ // noansi: set RX with check/try PLL is in Lock in RX
+ n = 5; // noansi: Try to set several times before giving up
+ do {
+ // enable RX
+ t = 255;
+ do {
+ ccStrobe(CC1100_SRX);
+ if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_RX) break;
+ my_delay_us(5);
+ } while (--t);
+
+ //if (!t) DS_P(PSTR("PLLNORX\r\n"));
+
+ if (!asksin_checkPLL()) return;
+ } while (--n);
+
+ //if (!n) DS_P(PSTR("PLLRXFAIL\r\n"));
+}
+
+static void
+rf_asksin_toTX(void)
+{
+ uint8_t n;
+ uint8_t t;
+
+ // noansi: set TX with check/try PLL is in Lock in TX
+ n = 5; // noansi: Try to set several times before giving up
+ do {
+ // enable TX, wait for CCA
+ t = 255;
+ do {
+ ccStrobe(CC1100_STX);
+ if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_TX) break;
+ my_delay_us(5);
+ } while (--t);
+
+ //if (!t) DS_P(PSTR("PLLNOTX\r\n"));
+
+ if (!asksin_checkPLL()) return;
+ } while (--n);
+
+ //if (!n) DS_P(PSTR("PLLTXFAIL\r\n"));
+}
+
+static uint8_t
+asksin_checkPLL(void)  // noansi: returns 0 on success
+{
+ uint8_t n;
+ uint8_t l;
+
+ // noansi: check PLL Lock and try to calibrate. Possibly restoring a saved calibration could be faster...
+ n = 5; // noansi: Try to recover several times before giving up
+ do
+ {
+ l = cc1100_readReg( CC1100_FSCAL1 );
+ if (l != 0x3f) return 0; // noansi: PLL in Lock as described in CC1101 doc and errata
+
+ // noansi: try to recover as no PLL Lock as described in CC1101 doc and errata
+      ccStrobe( CC1100_SIDLE );
+ DS_P(PSTR("PLLNOLOCK\r\n"));
+ // noansi: wait idle state, is it needed here?
+ l = 255;
+ do
+ {
+ if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_IDLE) break;
+ my_delay_us(1);
+ }
+ while (--l);
+
+ ccStrobe( CC1100_SCAL ); // noansi: Try Calibration
+
+ //if (!l) DS_P(PSTR("PLLNOIDLE\r\n"));
+
+ //my_delay_ms(1); // noansi: maybe waiting gives a better calibration instead of polling the state (noise)
+
+ // noansi: wait idle state -> calibration finished
+ l = 255;
+ do
+ {
+ if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_IDLE) break;
+ my_delay_us(10);
+ }
+ while (--l);
+
+ //if (!l) DS_P(PSTR("PLLNOCALIDLE\r\n"));
+ }
+ while (--n);
+
+ //rf_asksin_init(); // noansi: Try Init ... no could flood stack recursively...
+
+ l = cc1100_readReg( CC1100_FSCAL1 );
+ if (l != 0x3f) return 0; // noansi: PLL in Lock as described in CC1101 doc and errata
+
+ DS_P(PSTR("PLLLOCKFAIL\r\n"));
+
+ return 1; // noansi: error, no PLL Lock
+}
+
+
void
asksin_func(char *in)
{


Für die, die die komplette geänderte rf_asksin.c ansehen möchten:

Code Auswählen Erweitern

#include "board.h"
#ifdef HAS_ASKSIN
#include <string.h>
#include <avr/pgmspace.h>
#include "cc1100.h"
#include "delay.h"
#include "rf_receive.h"
#include "display.h"

#include "rf_asksin.h"

uint8_t asksin_on = 0;

const uint8_t PROGMEM ASKSIN_CFG[] = {
     0x00, 0x07,
     0x02, 0x2e,
     0x03, 0x0d,
     0x04, 0xE9,
     0x05, 0xCA,
     0x07, 0x0C,
     0x0B, 0x06,
     0x0D, 0x21,
     0x0E, 0x65,
     0x0F, 0x6A,
     0x10, 0xC8,
     0x11, 0x93,
     0x12, 0x03,
     0x15, 0x34,
     0x17, 0x33, // go into RX after TX, CCA; EQ3 uses 0x03
     0x18, 0x18,
     0x19, 0x16,
     0x1B, 0x43,
     0x21, 0x56,
     0x25, 0x00,
     0x26, 0x11,
     0x29, 0x59,
     0x2c, 0x81,
     0x2D, 0x35,
     0x3e, 0xc3
};

#ifdef HAS_ASKSIN_FUP
const uint8_t PROGMEM ASKSIN_UPDATE_CFG[] = {
     0x0B, 0x08,
     0x10, 0x5B,
     0x11, 0xF8,
     0x15, 0x47,
     0x19, 0x1D,
     0x1A, 0x1C,
     0x1B, 0xC7,
     0x1C, 0x00,
     0x1D, 0xB2,
     0x21, 0xB6,
     0x23, 0xEA,
};

static unsigned char asksin_update_mode = 0;
#endif

static void rf_asksin_reset_rx(void);
static void rf_asksin_toRX(void);
static void rf_asksin_toTX(void);
static uint8_t asksin_checkPLL(void);  // noansi: returns 0 on success


void
rf_asksin_init(void)
{

  EIMSK &= ~_BV(CC1100_INT);                 // disable INT - we'll poll...
  SET_BIT( CC1100_CS_DDR, CC1100_CS_PIN );   // CS as output

  CC1100_DEASSERT;                           // Toggle chip select signal
  my_delay_us(30);
  CC1100_ASSERT;
  my_delay_us(30);
  CC1100_DEASSERT;
  my_delay_us(45);

  ccStrobe( CC1100_SRES );                   // Send SRES command
  my_delay_us(100);

  // load configuration
  for (uint8_t i = 0; i < sizeof(ASKSIN_CFG); i += 2) {
    cc1100_writeReg( pgm_read_byte(&ASKSIN_CFG[i]),
                     pgm_read_byte(&ASKSIN_CFG[i+1]) );
  }

#ifdef HAS_ASKSIN_FUP
  if (asksin_update_mode) {
    for (uint8_t i = 0; i < sizeof(ASKSIN_UPDATE_CFG); i += 2) {
      cc1100_writeReg( pgm_read_byte(&ASKSIN_UPDATE_CFG[i]),
                       pgm_read_byte(&ASKSIN_UPDATE_CFG[i+1]) );
    }
  }
#endif

  ccStrobe( CC1100_SCAL );

  my_delay_ms(4);

  // enable RX, but don't enable the interrupt
// noansi: check PLL is in Lock in RX
rf_asksin_toRX();
}


static void
rf_asksin_reset_rx(void)
{
  ccStrobe( CC1100_SIDLE ); // noansi: if stuck in RX after RX OVERFLOW as described in CC1101 errata -> do SFRX only in IDLE as CC1101 doc
  ccStrobe( CC1100_SFRX  );
  //ccStrobe( CC1100_SIDLE );
  //ccStrobe( CC1100_SNOP  );
  //ccStrobe( CC1100_SRX   );
rf_asksin_toRX(); // noansi: try to set RX with calibration
}

void
rf_asksin_task(void)
{
  uint8_t msg[MAX_ASKSIN_MSG];
  uint8_t this_enc, last_enc;
  uint8_t rssi;
  uint8_t l;

  if(!asksin_on)
    return;

  // see if a CRC OK pkt has been arrived
  if (bit_is_set( CC1100_IN_PORT, CC1100_IN_PIN )) {
    msg[0] = cc1100_readReg( CC1100_RXFIFO ) & 0x7f; // read len

    if (msg[0] >= MAX_ASKSIN_MSG) {
      // Something went horribly wrong, out of sync?
      rf_asksin_reset_rx();
      return;
    }

    CC1100_ASSERT;
    cc1100_sendbyte( CC1100_READ_BURST | CC1100_RXFIFO );
   
    for (uint8_t i=0; i<msg[0]; i++) {
         msg[i+1] = cc1100_sendbyte( 0 );
    }
   
    rssi = cc1100_sendbyte( 0 );
    /* LQI = */ cc1100_sendbyte( 0 );

    CC1100_DEASSERT;

    rf_asksin_toRX();

    last_enc = msg[1];
    msg[1] = (~msg[1]) ^ 0x89;
   
    for (l = 2; l < msg[0]; l++) {
         this_enc = msg[l];
         msg[l] = (last_enc + 0xdc) ^ msg[l];
         last_enc = this_enc;
    }
   
    msg[l] = msg[l] ^ msg[2];
   
    if (tx_report & REP_BINTIME) {
     
      DC('a');
      for (uint8_t i=0; i<=msg[0]; i++)
      DC( msg[i] );
         
    } else {
      DC('A');
     
      for (uint8_t i=0; i<=msg[0]; i++)
        DH2( msg[i] );
     
      if (tx_report & REP_RSSI)
        DH2(rssi);
     
      DNL();
    }
  }

  switch(cc1100_readReg( CC1100_MARCSTATE )) {
    case MARCSTATE_RX:
// noansi: try init, if stuck in RX State with no PLL Lock as seen in extended read timeout logging
l = cc1100_readReg( CC1100_FSCAL1 );
if (l == 0x3f) { // noansi: no PLL Lock as described in CC1101 errata
l = cc1100_readReg( CC1100_FSCAL3 );
if (l == 0xaf) { // noansi: saw this too, if no data is received any more for a long period of time (up to 2 hours)
DS_P(PSTR("PLLERR\r\n"));
rf_asksin_init(); // noansi: try init to recover
return;
}
}
break;
    case MARCSTATE_RXFIFO_OVERFLOW:
      ccStrobe( CC1100_SIDLE ); // noansi: if stuck in RX after RX OVERFLOW as described in CC1101 errata -> do SFRX only in IDLE as CC1101 doc
      ccStrobe( CC1100_SFRX  );
    case MARCSTATE_IDLE:
      //ccStrobe( CC1100_SIDLE );
      //ccStrobe( CC1100_SNOP  );
      //ccStrobe( CC1100_SRX   );
rf_asksin_toRX(); // noansi: try to set RX with calibration
      break;
  }

if (asksin_checkPLL()) // noansi: check PLL is in Lock
{
rf_asksin_toRX(); // noansi: try to set RX with calibration
}
}

void
asksin_send(char *in)
{
  uint8_t msg[MAX_ASKSIN_MSG];
  uint8_t ctl;
  uint8_t l;

  uint8_t hblen = fromhex(in+1, msg, MAX_ASKSIN_MSG-1);

  if ((hblen-1) != msg[0]) {
//  DS_P(PSTR("LENERR\r\n"));
    return;
  }

  // in AskSin mode already?
  if(!asksin_on) {
    rf_asksin_init();
    my_delay_ms(3);             // 3ms: Found by trial and error
  }

  ctl = msg[2];

  // "crypt"
  msg[1] = (~msg[1]) ^ 0x89;

  for (l = 2; l < msg[0]; l++)
    msg[l] = (msg[l-1] + 0xdc) ^ msg[l];
 
  msg[l] = msg[l] ^ ctl;

// noansi: set TX with check/try PLL is in Lock in TX
rf_asksin_toTX();

  if (ctl & (1 << 4)) { // BURST-bit set?
    // According to ELV, devices get activated every 300ms, so send burst for 360ms
    for(l = 0; l < 3; l++)
      my_delay_ms(120); // arg is uint_8, so loop
  } else {
  my_delay_ms(10);
  }

  // send
  CC1100_ASSERT;
  cc1100_sendbyte(CC1100_WRITE_BURST | CC1100_TXFIFO);

  for(uint8_t i = 0; i < hblen; i++) {
    cc1100_sendbyte(msg[i]);
  }

  CC1100_DEASSERT;

  // wait for TX to finish
  while(cc1100_readReg( CC1100_MARCSTATE ) == MARCSTATE_TX)
    ;

  if (cc1100_readReg( CC1100_MARCSTATE ) == MARCSTATE_TXFIFO_UNDERFLOW) {
      ccStrobe( CC1100_SFTX  );
      ccStrobe( CC1100_SIDLE );
      ccStrobe( CC1100_SNOP  );
  }
 
  if(asksin_on) {
// noansi: set RX with check/try PLL is in Lock in RX
rf_asksin_toRX();
  } else {
    set_txrestore();
  }
}

static void
rf_asksin_toRX(void)
{
uint8_t n;
uint8_t t;

// noansi: set RX with check/try PLL is in Lock in RX
n = 5; // noansi: Try to set several times before giving up
do {
// enable RX
t = 255;
do {
ccStrobe(CC1100_SRX);
if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_RX) break;
my_delay_us(5);
} while (--t);

//if (!t) DS_P(PSTR("PLLNORX\r\n"));

if (!asksin_checkPLL()) return;
} while (--n);

//if (!n) DS_P(PSTR("PLLRXFAIL\r\n"));
}

static void
rf_asksin_toTX(void)
{
uint8_t n;
uint8_t t;

// noansi: set TX with check/try PLL is in Lock in TX
n = 5; // noansi: Try to set several times before giving up
do {
// enable TX, wait for CCA
t = 255;
do {
ccStrobe(CC1100_STX);
if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_TX) break;
my_delay_us(5);
} while (--t);

//if (!t) DS_P(PSTR("PLLNOTX\r\n"));

if (!asksin_checkPLL()) return;
} while (--n);

//if (!n) DS_P(PSTR("PLLTXFAIL\r\n"));
}

static uint8_t
asksin_checkPLL(void)  // noansi: returns 0 on success
{
uint8_t n;
uint8_t l;

// noansi: check PLL Lock and try to calibrate. Possibly restoring a saved calibration could be faster...
n = 5; // noansi: Try to recover several times before giving up
do
{
l = cc1100_readReg( CC1100_FSCAL1 );
if (l != 0x3f) return 0; // noansi: PLL in Lock as described in CC1101 doc and errata

// noansi: try to recover as no PLL Lock as described in CC1101 doc and errata
      ccStrobe( CC1100_SIDLE );
DS_P(PSTR("PLLNOLOCK\r\n"));
// noansi: wait idle state, is it needed here?
l = 255;
do
{
if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_IDLE) break;
my_delay_us(1);
}
while (--l);

ccStrobe( CC1100_SCAL ); // noansi: Try Calibration

//if (!l) DS_P(PSTR("PLLNOIDLE\r\n"));

//my_delay_ms(1); // noansi: maybe waiting gives a better calibration instead of polling the state (noise)

// noansi: wait idle state -> calibration finished
l = 255;
do
{
if (cc1100_readReg(CC1100_MARCSTATE) == MARCSTATE_IDLE) break;
my_delay_us(10);
}
while (--l);

//if (!l) DS_P(PSTR("PLLNOCALIDLE\r\n"));
}
while (--n);

//rf_asksin_init(); // noansi: Try Init ... no could flood stack recursively...

l = cc1100_readReg( CC1100_FSCAL1 );
if (l != 0x3f) return 0; // noansi: PLL in Lock as described in CC1101 doc and errata

DS_P(PSTR("PLLLOCKFAIL\r\n"));

return 1; // noansi: error, no PLL Lock
}


void
asksin_func(char *in)
{
#ifndef HAS_ASKSIN_FUP
  if(in[1] == 'r') {                // Reception on
#else
  if((in[1] == 'r') || (in[1] == 'R')) {                // Reception on
    if (in[1] == 'R') {
      asksin_update_mode = 1;
    } else {
      asksin_update_mode = 0;
    }
#endif
    rf_asksin_init();
    asksin_on = 1;

  } else if(in[1] == 's') {         // Send
    asksin_send(in+1);

  } else {                          // Off
    asksin_on = 0;

  }
}

#endif


Erfahrungsberichte und Verbesserungsvorschläge werden gerne entgegen genommen.


Gruß, Ansgar.

[rudolfkoenig]

Wäre schön, wenn Du das Speichertechnisch für CUL_V2 mal checken könntest.

Code Auswählen Erweitern

Size:
   text       data        bss        dec        hex    filename
  11404         16        313      11733       2dd5    CUL_V2_HM.elf

11404+16 = 11420 < 12288 (12k)

-> Flash reicht, und Moeglichkeiten zum optimieren der Groesse gibt es auch noch reichlich.

[martinp876]

Zum Thema Timing:
ein HM device ist timingseitig einer CUL aus 2 Gründen überlegen:
1) es sendet selbständig ACK => das wird man nicht in eine CUL einbauen können/wollen
2) es sendet einen Timestamp mit jeder empfangenen Message aus der Luft

Punkt 2) wäre der eingentliche Bringer, eine CUL voran zu bringen. Man müsste einen Timer  mit msec auflösung laufen lassen und diesen Zeitstempel zusammen mit der Nachricht an die Zentrale senden. Dort kann dann mit hinreichender Genauigkeit die Verzögerung zwischen RF-receiver und FHEM-verarbeitung ausgerechnet werden. So mache ich dies auch mit HMLAN.

Schön wäre auch ein keep-alive - also ein Ping. Das regelmässige senden und die Antwort (mit zeitstempel) addiert einen Level an Genauigkeit. Erfahrungsgemäß sind die Quarze sehr schlecht (ich vermute, HMLAN hat gar keinen Quarz - zumindest ist das Timing nicht davon abgeleitet - zu schlecht). Das Delay alle 30sec zu prüfen ist daher sehr hilfreich.

Gruss Martin

[tpm88]

@Tobias: Danke für Deine Problemnachricht. Zur Fritz!Box 7390 darf ich aus eigener Erfahrung sagen, dass die USB Stromversorgung da auch eine Rolle spielen kann (siehe auch Rudolfs und Jens Tipps und Hinweise zur Stromversorgung), zumindest mit USB-Sticks (CUL war noch nie daran angeschlossen) hatte ich da Probleme, die sich mit einem dickeren Netzteil beheben ließen. Das original Netzteil hatte das auch anfangs mit gemacht aber ist dann nach ca. 1 Jahr Betrieb etwas eingebrochen. Wenn Du also mehr als nur den CUL daran hängen hast, dann kann die Stromversorgung auch Problemursache sein.
Wenn Du nicht gerade einen CUL_V2 (und damit eventuell zu wenig Programmspeicherplatz) hasst, dann würde ich mich freuen, von Deinen Erfahrungen mit der Firmwareänderung zu lesen. Bitte auch den verbose Modus für den CUL auf 2 setzen, damit es im Log auch sichtbar wird.

Hi Ansgar,
Stromversorgung kann ich ausschliessen, denn es hängt zwar noch mehr dran an der 7390 - allerdings an einem aktiven Hub. Den CUL habe ich direkt an den zweiten USB-Port der FB7390 angeschlossen. Die FB7390 selbst wird von einem 12V 4A stabilisierten Labornetzteil gespeist. Da sollte nichts einbrechen...

Ich habe einen CUL_V3, mit dem Platz also auch keine Probleme. Könntest Du mir bitte die modifizierte Firmware als hex File schicken?
Dann teste ich gerne...

Gruss
Tobias

[noansi]

Hallo Martin, hallo Rudolf,

@Rudolf: Danke für den check. Jetzt ist mir die size Ausgabe klar, was den Programmspeicher angeht. Und schön, dass noch was geht.

@Martin: Ich dachte zwar eigentlich an einen Check, ob mit den Änderungen Timingprobleme zu befürchten sind.
Aber macht nix, einen ms Timer habe ich jetzt mal mit dem auf dem CUL noch freien Timer 3 am laufen und er spuckt mir nach jedem Empfangstelegramm noch eine Zeile mit TS<Zeitstempel><NL> aus. Der Zeitstempel ist ein 32bit ms Zähler, der dezimal ausgegeben wird. Natürlich läuft der Zähler auch mal über und beim CUL Neustart wird er auf 0 gesetzt.
Wie hättest Du denn gerne den Zeitstempel ausgegeben/angehangen/Hex ? Welches Komando für das ECHO und wie das Echo-Antwortformat???

Zu dumm, das Timer 3 bei CUR auch im Quelltext steht. Ganz so easy allgemein wird es also nicht.

Gruß, Ansgar.

[rudolfkoenig]

Das CUR stammt noch vor der HM@culfw Zeit, und es hat HM nie wirklich unterstuetzt, es sei denn, man verwendet das CUR als teuren CUL. Es gibt mWn insg. 3 Exemplare davon, du brauchst also keine Ruecksicht zu nehmen. Man muss nur "HAS_ASKSIN" aus Devices/CUR/board.h entfernen.

Der Zeitstempel muss an die A Nachricht angehaengt werden, damit in CUL.pm keine Sonderbehandlung noetig ist.

[tpm88]

Sicher, ich haette nur gerne noch feedback von einem weiteren Benutzer mit viel HM Hardware.

So - ich habe jetzt auch die von noansi modifizierte Firmware auf meinem CUL. Der Loglevel ist auf verbose 2 gesetzt.

Da bei mir die Aussetzer, die ich über den ActionDetector bemerkt habe, nur alle paar Tage auftraten, heisst es jetzt abzuwarten.

Tobias

[noansi]

Hallo Martin, hallo Rudolf,


zum Zeitstempel bei Asksin wäre mein Vorschlag:

- per default aus, da derzeit nicht bei allen CULs einbaubar

- Aktivierbar mit AT und de-aktivierbar mit At

- wird als T<Empfangs Zeitstempel in Hex> an die Nachricht angehangen, also AllnnffttssssssddddddppTtttttttt\r\n
   Der Zeitstempel wird nach dem Einlesen aus dem cc1101 FIFO und erneutem Aktivieren des Empfangs genommen.
   Da ohnehin nur gepollt wird, ob was angekommen ist, wird das ausreichend genau sein, denke ich.

- Ping mit Ap antwortet mit ATtttttttt\r\n


@Martin: Wenn es auch 16 Bit tun, dann nur Ttttt. Was brauchst Du?

@Rudolf: was ist mit dem RSSI? Da müsstest Du wohl noch eine Kleinigkeit ändern. Hab ich noch was übersehen?

Wenn Ihr damit einverstanden seid, dann ist es quasi in der Firmware für CUL_V3 fertig und läuft bei mir im Test.


Gruß, Ansgar.

[rudolfkoenig]

Wenn RSSI weiterhin hinten drangehaengt wird, dann nicht.

[tpm88]

Hallo Ansgar,

verändern deine Anpassungen an der Firmware irgendwie das Timing? Mir sind eben einige Fehler, Resends aufgefallen im HMinfo aufgefallen, die erst seit Einspielen der modifizierten CUL Firmware auftreten:

Code Auswählen Erweitern


protoEvents done:
    name                :State           |CmdPend           |Snd               |LastRcv       |Resnd             #CmdDel            |ResndFail         |Nack       
    az_Thermostat       : done           | -                |1:05-30 03:50:59  |05-30 21:49:54| -                # -                | -                | -         
    az_podP6026         : done           | -                |2:05-30 21:17:33  |05-30 21:17:33|3:05-30 21:17:33  # -                | -                | -         
    bd_Thermostat       : done           | -                |1:05-30 03:40:36  |05-30 21:50:44| -                # -                | -                | -         
    dg_Thermostat       : done           | -                |1:05-30 04:09:13  |05-30 21:50:53| -                # -                | -                | -         
    ke_Pumpe            : done_Errors:1  | -                |1:05-30 05:30:00  | -            |3:05-30 05:30:12  #1                 |1:05-30 05:30:17  | -         
    ke_Switch4          : done           | -                |1:05-30 15:32:44  |05-30 15:32:47|1:05-30 15:32:47  # -                | -                | -         
    ku_Switch1          : done           | -                |2:05-30 20:36:55  |05-30 20:36:55| -                # -                | -                | -         
    te_Markise          : done           | -                |12:05-30 21:05:49 |05-30 21:05:49|4:05-30 21:05:48  # -                | -                | -         
    wz_Thermostat       : done           | -                |1:05-30 01:58:07  |05-30 21:51:33| -                # -                | -                | -         
    wz_vT               : done           | -                |596:05-30 21:49:55| -            | -                #4                 | -                | -         
================================================================================================================
    sum                 1                |0                 |618               |40            |11                #5                 |1                 |0   


Da das mein Produktionssystem ist, habe ich seit einiger Zeit keine Updates eingespielt. Brauchen deine Modifikationen eine aktuelles CUL oder CUL_HM Modul ?

Code Auswählen Erweitern


# $Id: fhem.pl 5238 2014-03-16 16:23:31Z rudolfkoenig $
# $Id: 00_CUL.pm 5269 2014-03-20 21:22:59Z rudolfkoenig $
# $Id: 10_CUL_HM.pm 5262 2014-03-20 19:02:12Z martinp876 $

Tobias

[noansi]

Hallo Tobias,

Danke für Dein erstes Feedback.

Meine fhem.pl Basis hat die Version 5663 vom 26.4.14
00_CUL.pm Basis 5487 vom 8.4.14
10_CUL.pm Basis 5679 vom 27.4.14
Am Timing habe ich da nichts geändert, sondern nur für den Problemfall meine Timeout Behandlung eingebaut. Die machen aber im ms Bereich sicher keinen Unterschied.

Meine Änderungen betreffen im Timing in der Firmware die Umschaltung von Senden nach Empfang und umgekehrt, da jedes mal noch das CC1100_FSCAL1 ausgelesen und geprüft wird.
Edit: Die Prüfung erfolgt auch nach jedem Poll auf ein neues Paket, also bei jedem Taskdurchlauf.
Wenn ich am SPI Timing nichts übersehen habe, dann sind das aber nur Verzögerungen im niedrigen xx µs Bereich. Von daher erwarte ich da keine massiven Probleme, da Martin ja im ms Bereich unterwegs ist, was das Timing angeht. Aber ich kann mich da auch täuschen.
Das war eigentlich auch die Frage an Martin, ob er damit Probleme erwartet.

Edit: Hast Du mal ins Hauplog geschaut, ob da irgendwelche von den PLL Meldungen auftauchen? Wenn neu kalibriert werden muss, dann ist das mit mehr Zeitaufwand im knappen ms Bereich verbunden (so es beim ersten mal klappt, sonst bis zu mehreren ms).

Wie sah es denn mit der bisherigen Firmware bei den Resends aus?

Meine Erfahrung beim Senden bisher, und die habe ich bisher nur manuell ausgelöst, waren mit relativ häufigen Resends verbunden, auch vor meinen Änderungen an der Firmware. Verbesserungen bezüglich Empfangslage (RSSI) haben dabei zu Verbesserungen geführt.

Gruß, Ansgar.

[tpm88]

Hallo Ansgar,

Edit: Hast Du mal ins Hauplog geschaut, ob da irgendwelche von den PLL Meldungen auftauchen? Wenn neu kalibriert werden muss, dann ist das mit mehr Zeitaufwand im knappen ms Bereich verbunden (so es beim ersten mal klappt, sonst bis zu mehreren ms).

Nein - ich sehe keinerlei PLL Meldungen, seit ich die 1.59 Firmware eingespielt habe.

Wie sah es denn mit der bisherigen Firmware bei den Resends aus?

Es gab in der Vergangenheit schon mal den einen oder anderen Resend - vom Gefühl her vielleicht 1x pro Woche. Problem mit der 1.59 ist, dass praktisch jedes Kommando einen Resend und noch schlimmer häufig sogar einen Resend Failed ausgelöst hat.

Code Auswählen Erweitern

2014-05-30_22:31:37 az_podP6026 ResndFail
2014-05-30_22:31:37 az_podP6026 MISSING ACK
...
2014-05-31_07:02:46 ku_Switch1 ResndFail
2014-05-31_07:02:46 ku_Switch1 MISSING ACK
...
2014-06-01_07:30:18 ke_Pumpe ResndFail
2014-06-01_07:30:18 ke_Pumpe MISSING ACK
...
2014-06-01_17:48:16 ku_Switch1 ResndFail
2014-06-01_17:48:16 ku_Switch1 MISSING ACK
...
protoEvents done:
    name                :State           |CmdPend           |Snd               |LastRcv       |Resnd             #CmdDel            |ResndFail       
    az_Thermostat       : done           | -                |34:06-01 01:21:38 |06-01 17:49:29|2:05-30 22:48:03  # -                | -               
    az_podP6026         : done           | -                |8:06-01 17:47:29  |06-01 17:47:29|1:06-01 17:47:13  # -                | -               
    bd_Thermostat       : done           | -                |2:06-01 01:11:17  |06-01 17:49:50| -                # -                | -               
    dg_Thermostat       : done           | -                |2:06-01 01:39:55  |06-01 17:48:19| -                # -                | -               
    ke_Pumpe            : done           | -                |12:06-01 17:47:38 |06-01 17:47:38|8:06-01 17:47:37  #1                 |1:06-01 07:30:18
    ke_Switch4          : done           | -                |8:05-31 07:10:02  |05-31 07:20:12|5:05-31 07:10:07  #3                 |1:05-30 22:41:10
    ku_Switch1          : done_Errors:1  | -                |2:06-01 17:48:08  | -            |2:06-01 17:48:12  #2                 |2:06-01 17:48:16
    te_Markise          : done           | -                |5:06-01 17:48:53  |06-01 17:48:53|4:06-01 17:48:53  # -                | -               
    wz_Thermostat       : done           | -                |2:05-31 23:28:47  |06-01 17:48:45| -                # -                | -               
    wz_vT               : done           | -                |1025:06-01 17:49:58| -            | -                # -                | -             
================================================================================================================
    sum                 1                |0                 |1100              |47            |22                #6                 |4               


Meine Erfahrung beim Senden bisher, und die habe ich bisher nur manuell ausgelöst, waren mit relativ häufigen Resends verbunden, auch vor meinen Änderungen an der Firmware. Verbesserungen bezüglich Empfangslage (RSSI) haben dabei zu Verbesserungen geführt.

Die obigen Resends und Resend Failed betreffen mehrere Devices in verschiedenen Räumen. Ich hatte in der Vergangenheit eigentlich nur mit einem Device relativ schlechte RSSI Werte gehabt.

Zum Vergleich - eben habe ich wieder die Original 1.58 FW eingespielt und anschliessend auf jedes meiner HM Devices einen statusRequest und getConfig ausgelöst:

Kein einziger Resend, kein einziger Fehler, selbst bei den häufig etwas problematischen getConfig bei den RT-DN Thermostaten...

Code Auswählen Erweitern


protoEvents done:
    name                :State           |CmdPend           |Snd               |LastRcv       |Resnd             #CmdDel            |ResndFail       
    az_Thermostat       : done           | -                |29:06-01 18:14:10 |06-01 19:00:22| -                # -                | -               
    az_podP6026         : done           | -                |7:06-01 19:00:32  |06-01 19:00:32| -                # -                | -               
    bd_Thermostat       : done           | -                |29:06-01 18:20:45 |06-01 19:01:10| -                # -                | -               
    dg_Thermostat       : done           | -                |29:06-01 18:23:33 |06-01 18:59:25| -                # -                | -               
    ke_Pumpe            : done           | -                |7:06-01 19:00:44  |06-01 19:00:44| -                # -                | -               
    ke_Switch4          : done           | -                |11:06-01 18:03:32 |06-01 18:03:32| -                # -                | -               
    ku_Switch1          : done           | -                |9:06-01 19:00:51  |06-01 19:00:51| -                # -                | -               
    te_Markise          : done           | -                |9:06-01 18:03:56  |06-01 18:03:56| -                # -                | -               
    wz_Thermostat       : done           | -                |29:06-01 18:59:40 |06-01 19:00:05| -                # -                | -               
    wz_vT               : done           | -                |24:06-01 18:59:59 | -            | -                # -                | -               
================================================================================================================
    sum                 0                |0                 |183               |54            |0                 #0                 |0               


Zumindest mit einer FB7390 macht die v1.59 bei mir erhebliche Probleme beim Senden.

Gruss
Tobias

[noansi]

Hallo Tobias,


danke für Dein Feedback.


Ok, jetzt wäre etwas Protokollinfo zum Timing nicht verkehrt.
Hat dazu jemand Infos?

Kommen Acks und Antworten so schnell, dass die kleine Zusatzverzögerung diese Auswirkungen erklären kann?

Dann könnte ich nur in den Sendepausen mal prüfen, ob der PLL nicht mehr im Lock Zusand ist und müsste es beim Umschalten sein lassen, respektive so schnell wie möglich umschalten?


Gruß, Ansgar.

[noansi]

Hallo Rudolf und alle Mitleser,


ich habe nun 2 CULs am laufen und das nun auch an einem aktiven USB-Hub.

Das vorläufige Testergebnis nach über 4 Tagen Test zeigt bisher nur bei dem ersten CUL das Problem mit dem fehlenden PLL Lock.
Der neue CUL hat als Unterschied zum ersten noch den Metall-Schirm. Da ich aber in der Nähe keine großen erkennbaren Störsender/-quellen habe, denk ich nicht, dass das den Unterschied ausmacht.

Vielleicht habe ich auf dem CUL eine "Montags" cc1101 drauf oder eine Lötstelle ist nicht ganz sauber oder ein Pufferkondensator etwas schwach... und einen Software Workaround gefunden.

Sollte der Zweite sich doch nochmal mit dem beschriebenen Problem melden, werde ich berichten.

Unterschiedlich sind auf jeden Fall die Register Werte bei den FCAL Registern:

CUL_0 raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AE2A16114100597F3E81350B00
CUL_1 raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AC2B16114100597F3E81350B00

@Rudolf: Danke nochmal für die Hardwareanregungen und Deine Geduld!


Gruß, Ansgar.

[tpm88]

Das vorläufige Testergebnis nach über 4 Tagen Test zeigt bisher nur bei dem ersten CUL das Problem mit dem fehlenden PLL Lock.
Der neue CUL hat als Unterschied zum ersten noch den Metall-Schirm. Da ich aber in der Nähe keine großen erkennbaren Störsender/-quellen habe, denk ich nicht, dass das den Unterschied ausmacht.

Vielleicht habe ich auf dem CUL eine "Montags" cc1101 drauf oder eine Lötstelle ist nicht ganz sauber oder ein Pufferkondensator etwas schwach... und einen Software Workaround gefunden.

Hallo Ansgar,

ich glaube (noch) nicht an deine "Montags"-CUL.

Zwischenzeitlich habe ich  jetzt auch PLLNOLOCK geloggt. Insgesamt 4x in 3 Tagen, davon je 2x mit der modifizierten CUL FW 1.59 und 2x mit der 99.60.

Code Auswählen Erweitern


2014.06.02 14:58:30.497 4: CUL_send:  CUL_HMAs 0B 19 8670 119901 000000 00CC
2014.06.02 14:58:34.255 4: CUL_Parse: CUL_HM A 0F 75 8610 220839 000000 0A98CB0E060D37 -46.5
2014.06.02 14:58:35.579 4: CUL_Parse: CUL_HM A 0F 41 8610 21DE95 000000 0A88C50F005838 -46
2014.06.02 14:59:14.963 4: CUL_Parse: CUL_HM A 0F 37 8610 21DC30 000000 0A88CF0E005831 -49.5
2014.06.02 15:00:36.894 4: CUL_Parse: CUL_HM A 0F E9 8610 21F220 000000 0A88CC09006321 -57.5
2014.06.02 15:01:06.257 4: CUL_Parse: CUL_HM A 0F 76 8610 220839 000000 0A98CB0E060D37 -46.5
2014.06.02 15:01:08.827 4: CUL_Parse: CUL_HM P LL NO LOCK   
2014.06.02 15:01:08.872 2: CUL_HM: unknown message PLLNOLOCK
2014.06.02 15:01:08.879 4: CUL_Parse: CUL_HM A 0F 42 8610 21DE95 000000 0A88C50F005838 -46
2014.06.02 15:01:22.973 4: CUL_send:  CUL_HMAs 0B 1A 8670 119901 000000 00CC
2014.06.02 15:02:17.715 4: CUL_Parse: CUL_HM A 0F 38 8610 21DC30 000000 0A88CF0E005830 -50
2014.06.02 15:02:58.145 4: CUL_Parse: CUL_HM A 0F EA 8610 21F220 000000 0A88CC09006321 -57.5
2014.06.02 15:03:23.754 4: CUL_Parse: CUL_HM A 0F 77 8610 220839 000000 0A98CB0E070D36 -47
2014.06.02 15:03:27.578 4: CUL_Parse: CUL_HM A 0F 43 8610 21DE95 000000 0A88C50F005837 -46.5
...
2014.06.03 18:40:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.8
2014.06.03 18:45:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.8
2014.06.03 18:46:00 2: CUL_HM: unknown message PLLNOLOCK
2014.06.03 18:50:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.8
2014.06.03 18:55:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.8
...
2014.06.04 10:30:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.4
2014.06.04 10:35:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.4
2014.06.04 10:38:31 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 10:38:31 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 10:40:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.4
2014.06.04 10:45:00 2: CUL_HM set wz_vT_Sensor1 virtTemp 20.4
...
2014.06.04 20:52:22 3: ku_Switch1_off return value: OK
2014.06.04 20:52:52 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 20:52:52 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 20:53:16 0: Server shutdown


Ich habe den Umzug meines produktiven FHEM auf den RPi jetzt fast fertig. Wenn das stabil läuft, kann ich mit dem CUL auf der FB7390 künftig nach Herzenslust testen. Als nächsten Step werde ich die von Martin mit Timing versehene 00_CUL.pm aus http://forum.fhem.de/index.php/topic,24225.0.html einspielen.

Gruss
Tobias

[noansi]

Hallo Tobias,


danke für's mutige mit Testen.

Dann hat mein Workaround wohl doch seine Berechtigung, auch wenn nicht jede CUL davon betroffen zu sein scheint. Dann wäre die Mühe nicht vergebens gewesen.

Für eine Empfangsaussetzter Aussage ist es bei Dir wohl noch etwas früh, denke ich. Bei mir wirkts zumindest gut. Es besteht also Hoffnung auch für Dich.
Dann werde ich meine PLLNOLOCK Ausgabe wohl auch drin lassen. Vielleicht mache ich sie abschaltbar.

Kannst Du bitte mal get raw C99 prüfen und Deine Ausgabe hier posten zum Registervergleich.


Gruß, Ansgar.

[tpm88]

Hallo Ansgar,

hier im Vergleich meine (CUL_HM) Registerwerte zu den von dir bereits weiter oben berichteteten (CUL_0 und CUL_1):


CUL_0 raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AE2A16114100597F3E81350B00
CUL_1 raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AC2B16114100597F3E81350B00 
CUL_HM raw => 072E2E0DE9CAFF0C450000060021656AC8930322F834073318166C434091876BF85610AD2B17114100597F3E81350B00


Kann der "Laie" aus den unterschiedlichen Registerwerten etwas herauslesen?

Gruss
Tobias

PS: Die von Martin angepasste 00_CUL.pm mit Timing habe ich seit gestern auch in Betrieb. Ein Update der gesamten FHEM Installation war aus meiner Sicht bisher nicht notwendig. Die Kombination läuft mit deiner CUL FW 99.60 bisher ohne Auffälligkeiten.

[noansi]

Hallo Tobias,


mich interessieren die Registerwerte nur in sofern, als es interessant gewesen wäre, ein auffälliges Verhalten für weniger PLL-stabile CULs zu erkennen. Aber es sieht nicht danach aus. Die Register sind auch in der Chip-Doku nicht im Detail beschrieben.
Vielleicht sind manche Transceiver bei der Abstimmung nahe an der Grenze zwischen verschiedenen Einstellungen und kippen dann über Temperatur und Spannungsschwankungen, während andere satt mitten in ener Einstellung liegen und dann stabil mit PLL Lock laufen? Aber das ist nur eine schwache Vermutung.
Bei meiner Problem CUL ändern sich die Werte schon mal mit der Rekalibrierung nach einem PLLNOLOCK Event.

Da die Chipdoku aber empfiehlt, den PLL-Lock Zustand vor Senden und Empfang zu prüfen, was bisher in der Firmware 1.58 nicht drin war, bewegen wir uns nicht in einem fehlerhaften Verhalten.

Bei mir sieht der Test mit TimeStamp Firmware und Test 00_CUL auch gut aus. Resends sehe ich nur noch ganz selten. Und die können durch zeitfressende Aktionen anderer Module verursacht sein, so dass es nicht mehr möglich ist eine Ack Nachricht rechtzeitig auf den Weg zu bringen. Apptime gibt Hinweise dazu mit mittleren und maximalen Ausführungszeiten. Sendefehler habe bei nunmehr über 600 Sendeevents nicht gesehen.

Es bringt übrigens nichts, die Test 00_CUL mit einer älteren Firmware zu testen, da dann im besten Fall nichts passiert und bei Test der älteren Varianten der Empfang wegen des unbekannten Einschaltbefehls zur "Strafe" abgeschaltet wird. 


Gruß, Ansgar

[tpm88]

Hallo Ansgar,

deine PLLNOLOCK Erweiterungen zur CUL-Firmware haben bei mir definitiv die Stabilität verbessert. Vorher mit CUL FW 1.58 hatte ich häufig schlagartig Komplettausfälle (kein Empfang, kein Senden mehr möglich) der CUL Kommunikatiotion. Der ActionDetector meldet dann den gleichzeitigen Ausfall meiner 4 HM Thermostate. Hier alle Ausfälle vom Mai:

Code Auswählen Erweitern

2014-05-04_13:03:47 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-07_09:10:49 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-08_16:11:42 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-08_22:51:50 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-12_10:57:21 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-14_07:17:49 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-20_03:37:23 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-20_19:57:32 ActionDetector alive:0 dead:4 unkn:0 off:0
2014-05-28_21:12:27 ActionDetector alive:0 dead:4 unkn:0 off:0


Meist hat es dann zwischen einer und mehreren Stunden gedauert, bis die Kommunikation plötzlich wieder funktioniert hat. Seit 29.05. teste ich jetzt die CUL-Firmware mit den PLLNOLOCK Erweiterungen von noansi. Seitdem hat der ActionDetektor keinen einzigen Ausfall mehr registriert. Die PLLNOLOCK Routine wurde seither einige Mal aufgerufen:

Code Auswählen Erweitern

# grep -i pll fhem-2014-06.log
2014.06.02 15:01:08.872 2: CUL_HM: unknown message PLLNOLOCK
2014.06.03 18:46:00 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 10:38:31 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 10:38:31 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 20:52:52 2: CUL_HM: unknown message PLLNOLOCK
2014.06.04 20:52:52 2: CUL_HM: unknown message PLLNOLOCK
2014.06.09 09:03:52.392 2: CUL_HM: unknown message PLLNOLOCK
2014.06.10 08:22:44.579 2: CUL_HM: unknown message PLLNOLOCK
2014.06.11 00:14:16.083 2: CUL_HM: unknown message PLLNOLOCK
2014.06.11 14:17:02.237 2: CUL_HM: unknown message PLLNOLOCK


Die in v1.61 ebenfalls eingebaute Timingfunktionalität für CUL hat zusammen mit der von Martin hierfür modifizierten 00_CUL.pm zu messbar (HMinfo protoEvents Auswertung) weniger HomeMatic Resends bei meiner Konfiguration gesorgt. Vom Gefühl tragen die Timinganpassungen gerade für meine langsame Plattformen FritzBox7390 deutlich zur Stabilität von HM mit CUL bei.

Probleme (Senden) hatte ich nur mit CUL FW v1.59 (siehe mein Beitrag vom 01.06. hier)

Bitte beide Erweiterungen unbedingt in das FHEM Repository aufnehmen.

Gruss
Tobias

[noansi]

Hallo Leute,


Rudolf hat mit der Version 1.59 der CUL Firmware heute die Änderungen bezüglich PLL Lock Problematik für AskSin eingecheckt.

Damit sollte das ursprüngliche Problem dieses Threads mit Homematik Aussetzern bei Empfang und Versand nun gelöst sein.

Die Meldung im Hauptlog, falls das PLL Lock Problem erkannt wurde (und die CUL auf verbose 2 eingestellt ist) lautet nun "PLL0" statt "PLLNOLOCK". Das ist nur ein Hinweis und mit der Rekalibrierung, die dann erfolgt, sollte der Tranceiver wieder in den Tritt kommen.

Falls die dann versuchte Rekalibrierung scheitert erscheint zusätzlich "PLL1".

Wenn "PLL1" abwechselnd mit "PLL0" in kurzen Abständen wiederholt auftaucht, dann ist was faul mit der Hardware, wenn ich meine "Problem" CUL mal als Maßstab nehmen darf. "PLL1" ist noch nicht vorgekommen. Dafür pro Tag bis zu 10 mal "PLL0" in wechselnden Zeitabständen.


Gruß, Ansgar.

PS: Noch nicht drin ist die TimeStamp Option. Damit habe ich noch etwas Arbeit.

[frank]

Rudolf hat mit der Version 1.59 der CUL Firmware heute die Änderungen bezüglich PLL Lock Problematik für AskSin eingecheckt.

wegen diesem feature habe ich meinen cul gerade von culfw 1.58 auf die aktuelle culfw 1.67 (cul_v3.hex) updated.

da ich seit einem jahr 2x einen "ausfall" des cul hatte, habe ich die hoffnung, dass es eventuell ebenfalls ein PLL-Lock problem war.


ist dieses feature in der cul_v3.hex von culfw 1.67 noch aktiv?
gibt es in fhem.log noch eine mitteilung, falls das problem erkannt wurde?
wie sieht die meldung genau aus, damit ich ein notify triggern kann?

zeigen die beiden culs aus diesem thread immer noch das problem?
oder hat es sich eventuell erledigt, da zb eine neue "cul-umgebung" existiert?
oder sind sie mittlerweile sogar "verstorben"?

im forum kann ich zu "PLL" nicht viel finden. kann aber auch an der forumssuche liegen.


gruss frank

[noansi]

Hallo Frank,

ist dieses feature in der cul_v3.hex von culfw 1.67 noch aktiv?

Ist zumindest im Code vorhanden und bei aktivem ASKSIN Empfang dann auch aktiv. Das hex File habe ich nicht rückwärts danach untersucht.

gibt es in fhem.log noch eine mitteilung, falls das problem erkannt wurde?

Es sind weiterhin die PLL0 und PLL1 messages vom CUL, die in 00_CUL.pm schlicht an die Dispatch Funktion weiter gereicht werden. Und falls sich kein Modul dafür zuständig fühlt, sollte ein UNKNOWN PLL0 oder UNKNOWN PLL1 Trigger ausgelöst werden.

Code Auswählen Erweitern

      DoTrigger($name, "UNKNOWNCODE $dmsg");
      Log3 $name, 3, "$name: Unknown code $dmsg".
                     (defined($addvals) && defined($addvals->{RSSI})?", RSSI $addvals->{RSSI}":'').
                     ', help me!';

Meine CULs laufen noch prima, erfreuen sich aber der tsculfw. 

Gruß, Ansgar.

[frank]

danke, hat wunderbar funktioniert.

nach gut 6 wochen mit culfw 1.67 hat es heute nacht ein erstes PLL0 ereignis gegeben und der cul läuft weiterhin ohne probleme. 

Code Auswählen Erweitern

2024.01.27 02:37:48.041 4: CUL_Parse: cul868 A 0C 70 8670 20DFE1 000000 003556E8 -86
2024.01.27 02:37:48.048 5: cul868: dispatch A0C70867020DFE1000000003556::-86:cul868
2024.01.27 02:37:48.169 0: HMLAN_Parse: hmlan1 R:E20DFE1   stat:0000 t:F2281016 d:FF r:FFAE     m:70 8670 20DFE1 000000 003556
2024.01.27 02:37:56.011 0: HMLAN_Send:  hmlan1 S:S4890F6B8 stat:  00 t:00000000 d:01 r:4890F6B8 m:D8 A258 B6B6B6 1F91AA 0017
2024.01.27 02:37:56.051 4: CUL_Parse: cul868 A 0B D8 A258 B6B6B6 1F91AA 001739 -45.5
2024.01.27 02:37:56.054 5: cul868: dispatch A0BD8A258B6B6B61F91AA0017::-45.5:cul868
2024.01.27 02:37:56.060 4: CUL_Parse: cul868 P LL 0   
2024.01.27 02:37:56.063 5: cul868: dispatch PLL0
2024.01.27 02:37:56.065 3: cul433 IT_set: IT06 on
2024.01.27 02:37:56.833 3: cul868: Unknown code PLL0, help me!
2024.01.27 02:37:56.835 3: cul433 IT_set: IT06 on
2024.01.27 02:37:57.518 0: HMUARTLGW hmuart1 recv: 01 05 00 00 25 msg: D8 A2 58 B6B6B6 1F91AA 0017
2024.01.27 02:37:57.523 0: HMUARTLGW hmuart1 recv: 01 05 00 00 4B msg: D8 82 02 1F91AA B6B6B6 010114003D
2024.01.27 02:37:57.581 0: HMUARTLGW hmuart1 recv: 01 05 00 00 25 msg: D8 A2 58 B6B6B6 1F91AA 0017
2024.01.27 02:37:57.587 0: HMUARTLGW hmuart1 recv: 01 05 00 00 25 msg: D8 A2 58 B6B6B6 1F91AA 0017
2024.01.27 02:37:57.594 4: CUL_Parse: cul868 A 0E D8 8202 1F91AA B6B6B6 010114003DF0 -82
2024.01.27 02:37:57.598 5: cul868: dispatch A0ED882021F91AAB6B6B6010114003D::-82:cul868
2024.01.27 02:37:57.650 4: CUL_Parse: cul868 A 0B D8 A258 B6B6B6 1F91AA 001738 -46
2024.01.27 02:37:57.653 5: cul868: dispatch A0BD8A258B6B6B61F91AA0017::-46:cul868
2024.01.27 02:37:57.658 4: CUL_Parse: cul868 A 0B D8 A258 B6B6B6 1F91AA 001738 -46
2024.01.27 02:37:57.660 5: cul868: dispatch A0BD8A258B6B6B61F91AA0017::-46:cul868
2024.01.27 02:37:57.664 4: CUL_Parse: cul868 A 14 3E 805E 266EA5 1ACE1F 000000000000000000000028 -54
2024.01.27 02:37:57.667 5: cul868: dispatch A143E805E266EA51ACE1F0000000000000000000000::-54:cul868
2024.01.27 02:37:57.682 0: HMUARTLGW hmuart1 recv: 01 05 00 00 31 msg: 3E 80 5E 266EA5 1ACE1F 0000000000000000000000
2024.01.27 02:37:57.687 0: HMLAN_Parse: hmlan1 R:E1F91AA   stat:0000 t:F2282FD9 d:FF r:FFC3     m:D8 8202 1F91AA B6B6B6 010114003D
2024.01.27 02:37:57.709 0: HMLAN_Parse: hmlan1 R:R4890F6B8 stat:0008 t:00000000 d:FF r:7FFF     m:D8 A258 B6B6B6 1F91AA 0017
2024.01.27 02:37:57.711 0: HMLAN_Parse: hmlan1 no ACK from 1F91AA
2024.01.27 02:37:57.713 0: HMLAN_Parse: hmlan1 R:E266EA5   stat:0000 t:F228354B d:FF r:FFC2     m:3E 805E 266EA5 1ACE1F 0000000000
somit könnte der berichtete ausfall tatsächlich durch ein PLL problem verursacht worden sein.
als verursacher habe ich jetzt einen aktiven usb hub in verdacht, den ich kurz vor dem ersten cul ausfall zusätzlich am pi angeschlossen habe.
vorher gab es jahre lang null probleme.



ausserdem habe ich nun mit der neuen fw 2x err:cca gehabt.
mich wundert allerdings, dass es dabei jedes mal ein "reconnect" gegeben hat.
wenn ich mir logs im forum mit err:cca meldungen anschaue, sehe ich dort keine reconnects.

ist das verhalten durch die fw erklärbar, zb ein reopen?

Code Auswählen Erweitern

2024.01.13 20:28:00.472 4: CUL_Parse: cul868 A 14 D6 805E 266EA5 1ACE1F 000000000000000000000029 -53.5
2024.01.13 20:28:00.477 5: cul868: dispatch A14D6805E266EA51ACE1F0000000000000000000000::-53.5:cul868
2024.01.13 20:28:00.490 0: HMUARTLGW hmuart1 recv: 01 05 01 00 2F msg: D6 80 5E 266EA5 1ACE1F 0000000000000000000000
2024.01.13 20:28:00.495 0: HMLAN_Parse: hmlan1 R:E266EA5   stat:0000 t:ADE07F15 d:FF r:FFC6     m:D6 805E 266EA5 1ACE1F 0000000000000000000000
2024.01.13 20:28:16.604 5: cul868 sending As0BDBA258B4B4B41CE9F500FD
2024.01.13 20:28:16.607 5: DevIo_SimpleWrite cul868: As0BDBA258B4B4B41CE9F500FD
2024.01.13 20:28:18.117 4: CUL_Parse: cul868 E RR :C CA   
2024.01.13 20:28:18.123 5: cul868: dispatch ERR:CCA
2024.01.13 20:28:18.221 3: cul868: Unknown code ERR:CCA, help me!
2024.01.13 20:28:18.567 1: /dev/serial/by-id/usb-busware.de_CUL868-if00 disconnected, waiting to reappear (cul868)
2024.01.13 20:28:19.334 3: Setting cul868 serial parameters to 38400,8,N,1
2024.01.13 20:28:19.442 5: DevIo_SimpleWrite cul868: V
2024.01.13 20:28:19.448 5: DevIo_SimpleWrite cul868: ?
2024.01.13 20:28:19.498 3: cul868: Possible commands: ABbCeFGhiKkLlMmNRTtUuVWXxYZ
2024.01.13 20:28:19.501 5: DevIo_SimpleWrite cul868: X21
2024.01.13 20:28:19.505 5: DevIo_SimpleWrite cul868: Ar
2024.01.13 20:28:19.509 5: DevIo_SimpleWrite cul868: T01
2024.01.13 20:28:19.515 5: GOT CUL fhtid: 0000
2024.01.13 20:28:19.555 1: /dev/serial/by-id/usb-busware.de_CUL868-if00 reappeared (cul868)
2024.01.13 20:28:19.591 0: HMLAN_Parse: hmlan1 R:E266EA5   stat:0000 t:ADE0C8C2 d:FF r:FFC6     m:D7 805E 266EA5 1ACE1F 0000000000000000000000
2024.01.13 20:28:19.600 0: HMUARTLGW hmuart1 recv: 01 05 01 00 2F msg: D7 80 5E 266EA5 1ACE1F 0000000000000000000000

gruss frank

[noansi]

Hallo Frank,

als verursacher habe ich jetzt einen aktiven usb hub in verdacht, den ich kurz vor dem ersten cul ausfall zusätzlich am pi angeschlossen habe.

Da das PLL-Lock Problem ein in den Erratas zum CC1101 dokumentiertes Verhalten ist, halte ich den USB Hub für die PLL0 Meldung für wenig verdächtig?!

Natürlich kann ein USB-Hub für USB-Kommunikationsprobleme sorgen. Was sagt das Log vom Host dazu?

mich wundert allerdings, dass es dabei jedes mal ein "reconnect" gegeben hat.

Dein Log deutet fast 2 Sekunden ab dem As... bis zum reconnect. Der Watchdog des CUL würde bei 2s +/-Ungenauigkeit zuschlagen.
Möglich, dass das die Ursache ist?
Die CCA Wartezeit beim ASKSIN Senden ist in der Firmware zu 752ms gewählt, das alleine kann es also bezüglich Watchdog nicht sein.

Gruß, Ansgar.

[frank]

moin ansgar,

Da das PLL-Lock Problem ein in den Erratas zum CC1101 dokumentiertes Verhalten ist, halte ich den USB Hub für die PLL0 Meldung für wenig verdächtig?!

Natürlich kann ein USB-Hub für USB-Kommunikationsprobleme sorgen. Was sagt das Log vom Host dazu?

wenn du diese errata info meinst, verstehe ich die aussage nicht wirklich.

SWRZ020E–April 2007–Revised September 2015
PLL Lock Detector Output —PLL lock detector output is not 100% reliable

dort wird ja "nur" auf einen "unsicheren" pll-lock-check hingewiesen.
hinweise auf eine ursache für den verlust des pll-lock gibt es hier ja nicht.

im syslog gibt es zu dieser zeit gar nichts. auch grundsätzlich gibt es nichts ungewöhnliches zum usb.


bei den homebrew entwicklern von asksin++ wurde das pll_out_of_lock problem letztens übrigens auch entdeckt und ähnlich gefixt.
im thread etwa ab diesem post: https://homematic-forum.de/forum/viewtopic.php?f=76&t=78078&start=80#p767754
die ursache bleibt auch hier im dunkeln.
interessant finde ich die dort gefundenene aussage eines ti mitarbeiters zu diesem thema (scheinbar etwas voodoo  ):

From what you describe I can't give a good explanation why a few devices fails to calibrate some times. For a constant environment (temp, voltage etc) it should be sufficient with one calibration and not having to do a calibration again but for practical applications we always advice to calibrate at given time intervals since it's not possible to know all the reasons if/ why the PLL could go out of lock.

###################### zum reopen bei err:cca

Dein Log deutet fast 2 Sekunden ab dem As... bis zum reconnect. Der Watchdog des CUL würde bei 2s +/-Ungenauigkeit zuschlagen.
Möglich, dass das die Ursache ist?
Die CCA Wartezeit beim ASKSIN Senden ist in der Firmware zu 752ms gewählt, das alleine kann es also bezüglich Watchdog nicht sein.

ich hatte diese aussage von michael gefunden, da waren es scheinbar noch 2 sekunden.

ihr habt einen Störsender auf 868,35MHz, der CUL wechselt nicht in den Sendemodus, weil das Clear Channel Assessment nicht innerhalb von 2s erfolg hatte.

ich werde weiter beobachten, bisher keine neuen ereignisse.

[noansi]

Hallo Frank,

dafür Hinweise im Datenblatt:

22.1  VCO and PLL Self-Calibration
... This calibration should be done regularly,
... The PLL must be re-calibrated until PLL lock is achieved if the PLL
does not lock the first time.
... Since the  current  calibration values are only
valid for a finite temperature range (typically
±40C) the PLL must be re-calibrated if the lock
indicator does not indicate PLL lock

Und praktisch hatte ich geloggt, dass es bei meinen CULs gelegentlich zu PLL Lock Verlust gekommen ist.

bei den homebrew entwicklern von asksin++ wurde das pll_out_of_lock problem letztens übrigens auch entdeckt und ähnlich gefixt.

Warum sollte es anderen besser gehen, als mir. In dem Thread interessante Theorieansätze zur Ursache...

ich hatte diese aussage von michael gefunden, da waren es scheinbar noch 2 sekunden.

Code Auswählen Erweitern

  // enable TX, wait for CCA
  get_timestamp(&ts1);
  do {
    ccStrobe(CC1100_STX);
    if (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_TX) {
      get_timestamp(&ts2);
      if (((ts2 > ts1) && (ts2 - ts1 > ASKSIN_WAIT_TICKS_CCA)) ||
          ((ts2 < ts1) && (ts1 + ASKSIN_WAIT_TICKS_CCA < ts2))) {
        DS_P(PSTR("ERR:CCA\r\n"));
        goto out;
      }
    }
  } while (cc1100_readReg(CC1100_MARCSTATE) != MARCSTATE_TX);
mit

Code Auswählen Erweitern

#define ASKSIN_WAIT_TICKS_CCA 188 //125 Hz
und ups, 8ms, statt 4ms, wie bei der tsculfw -> macht 1504ms bei der culfw.
Immer noch keine 2s, aber mit blödem Zufall und 360ms Burst + Sendenachricht nicht mehr weit weg...
In der tsculfw ist der watchdog übrigens auf 8s statt 2s eingestellt. Den watchdog könntest Du also verändern und neu compilieren.
Außerdem hatte ich den USB Registerzugriff und Ringbufferzugriff atomarer gestaltet und generell "Textausgabe" aus Interrupts raus eliminiert, weil die Ausgaberoutinen dafür nie gemacht waren.

Gruß, Ansgar.

[frank]

hallo ansgar,

letztens habe ich dieses pdf von eq3 gefunden: https://www.homematic-inside.de/media/download/legacy/meetup_2018/sendeverhalten
auf seite 9 wird der aufbau von hmip telegrammen beschrieben, die demnach bis zu 61 Byte lang sein können.

in rf_asksin.c gibt es diese behandlung von "zu langen" (>= 30/50 byte) telegrammen:

Code Auswählen Erweitern

  // see if a CRC OK pkt has been arrived
  if (bit_is_set( CC1100_IN_PORT, CC1100_IN_PIN )) {
    msg[0] = cc1100_readReg( CC1100_RXFIFO ) & 0x7f; // read len

    if (msg[0] >= MAX_ASKSIN_MSG) {
      // Something went horribly wrong, out of sync?
      rf_asksin_reset_rx();
      return;
    }
nun frage ich mich, ob der empfang langer hmip messages und der damit verursachte aufruf von rf_asksin_reset_rx() zu verzögerungen führt, wodurch der watchdog auslöst.


ich denke man sollte hier die maximale länge ändern, so dass auch alle hmip messages erfasst werden.

nützlich könnte eine zusätzlich hmip erkennung sein, um diese messages erst gar nicht weiter zu leiten. vermutlich sind sie über die ersten 3 byte nach dem längen-byte eindeutig zu unterscheiden. vielleicht reicht schon das 2. byte, wenn ich mir die hmip messages anschaue, die ich hin und wieder in meinem log sehe.

gruss frank

[noansi]

Hallo Frank,

auf seite 9 wird der aufbau von hmip telegrammen beschrieben, die demnach bis zu 61 Byte lang sein können.

Danke für die Info, auch die vor Seite 9. 

in rf_asksin.c gibt es diese behandlung von "zu langen" (>= 30/50 byte) telegrammen

Was nach der Info vor Seite 9 nicht ganz passt, weder die 30, noch die 50. Lediglich als Pufferüberlaufschutz funktional.
26 wäre max. für ein Datentelegramm für das Längenbyte. Bei FUP können es 39 für das Längenbyte sein, nach meinem bisherigen Erfahrungsstand.

rssi und lqi werden vom cc1101 nur im fifo angehangen, zählen also ebenso wenig mit, wie die crc bytes.

nun frage ich mich, ob der empfang langer hmip messages und der damit verursachte aufruf von rf_asksin_reset_rx() zu verzögerungen führt, wodurch der watchdog auslöst.

Code Auswählen Erweitern

static void
rf_asksin_reset_rx(void)
{
  ccStrobe( CC1100_SFRX  );
  ccStrobe( CC1100_SIDLE );
  ccStrobe( CC1100_SNOP  );
  ccStrobe( CC1100_SRX   );
}
Das sind nur 4 Kommando Bytes, die nacheinander über den SPI an den cc1101 gejagt werden. Das kratzt nicht am watchdog.

Allerdings können die längeren HMIP messages eher zu

RXFIFO_OVERFLOW Issue

in den erratas führen. Und dazu ist dann die Empfehlung

When the radio is stuck in RX state like this, it will draw current as in RX state, but it will
not be able to receive any more data. The only way to get out of this state is to issue an
SIDLE strobe and then flush the FIFO (SFRX).

Was obiger Code nicht macht.

In der tsculfw ist dazu mehr Code drin.

nützlich könnte eine zusätzlich hmip erkennung sein, um diese messages erst gar nicht weiter zu leiten. vermutlich sind sie über die ersten 3 byte nach dem längen-byte eindeutig zu unterscheiden. vielleicht reicht schon das 2. byte, wenn ich mir die hmip messages anschaue, die ich hin und wieder in meinem log sehe.

Fände ich auch nützlich.
Und was sind die eindeutigen Merkmale zur Unterscheidung in den 3 Bytes?
Ab Seite 9 sehe ich leider zu wenig Details zur Unterscheidung.

Zum Telegrammzähler hat der CUL null Sinninfo.
Bei den Steuerungsbits darf nur Bit 3 nicht gesetzt sein.
Die bekannten Rahmentypen sind begrenzt.

Der CUL Flashspeicher und Speicher ist auch begrenzt.

Gruß, Ansgar.

[noansi]

Hallo Frank.

die maximale Paketlänge sollte sich filtern lassen, indem das PKTLEN Register 0x06 des cc1101 benutzt wird. Siehe auch "15.3.2  Maximum Length Filtering" Im cc1101 datasheet. rf_asksin.c Änderung:

Code Auswählen Erweitern

const uint8_t PROGMEM ASKSIN_CFG[] = {
     0x00, 0x07,
     0x02, 0x2e,
     0x03, 0x0d,
     0x04, 0xE9,
     0x05, 0xCA,
     0x06, 26, // maximum lenght of data without length byte. Set also to avoid RXFIFO_OVERFLOW issue in errata
     0x07, 0x0C,
     0x0B, 0x06,
     0x0D, 0x21,
     0x0E, 0x65,
     0x0F, 0x6A,
     0x10, 0xC8,
     0x11, 0x93,
     0x12, 0x03,
     0x15, 0x34,
     0x17, 0x33, // go into RX after TX, CCA; EQ3 uses 0x03
     0x18, 0x18,
     0x19, 0x16,
     0x1B, 0x43,
     0x21, 0x56,
     0x25, 0x00,
     0x26, 0x11,
     0x29, 0x59,
     0x2c, 0x81,
     0x2D, 0x35,
     0x3e, 0xc3
};

#ifdef HAS_ASKSIN_FUP
const uint8_t PROGMEM ASKSIN_UPDATE_CFG[] = {
     0x06, 39, // maximum lenght of data without length byte. Set also to avoid RXFIFO_OVERFLOW issue in errata
     0x0B, 0x08,
     0x10, 0x5B,
     0x11, 0xF8,
     0x15, 0x47,
     0x19, 0x1D,
     0x1A, 0x1C,
     0x1B, 0xC7,
     0x1C, 0x00,
     0x1D, 0xB2,
     0x21, 0xB6,
     0x23, 0xEA,
};

Also minimaler Eingriff. 

Gruß, Ansgar.

[frank]

hallo ansgar,

in rf_asksin.c gibt es diese behandlung von "zu langen" (>= 30/50 byte) telegrammen

Was nach der Info vor Seite 9 nicht ganz passt, weder die 30, noch die 50. Lediglich als Pufferüberlaufschutz funktional.
26 wäre max. für ein Datentelegramm für das Längenbyte. Bei FUP können es 39 für das Längenbyte sein, nach meinem bisherigen Erfahrungsstand.

ich habe ein altes FUP (HM-LC-SW1PBU-FM, alternative fw über hmusb mit eq3 software) gefunden mit 46 bytes.

Code Auswählen Erweitern

2014.10.24 12:18:16.698 0: HMLAN_Parse: hmlan1 R:E266E75   stat:0000 t:08B25141 d:FF r:FFC5     m:00 0010 266E75 000000 004B455131313039373937
2014.10.24 12:18:16.720 0: HMLAN_Parse: hmusb1 R:E266E75   stat:0000 t:09D61EA4 d:FF r:FFBB     m:00 0010 266E75 000000 004B455131313039373937
2014.10.24 12:18:16.974 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:08B25255 d:FF r:FFB5     m:42 00CB 1ACE1F 266E75 105B11F81547
2014.10.24 12:18:17.017 0: HMLAN_Parse: hmusb1 R:E1ACE1F   stat:0000 t:09D61FB9 d:FF r:FFCC     m:42 00CB 1ACE1F 266E75 105B11F81547
2014.10.24 12:18:17.076 4: CUL_Parse: cul868 A 0F 43 20CB 1ACE1F 266E75 105B11F815471F -58.5
2014.10.24 12:18:17.113 4: CUL_Parse: cul868 A 0A 43 8002 266E75 1ACE1F 0032 -49
2014.10.24 12:18:17.161 4: CUL_Parse: cul868 A 2E 44 00CA 1ACE1F 266E75 01000C942C710C94D4710C9449710C9449710C9449710C9449710C9449710C9449710C94491F -58.5
2014.10.24 12:18:17.195 4: CUL_Parse: cul868 A 2C 44 00CA 1ACE1F 266E75 710C9449710C9449710C9449710C9449710C9449710C9449710C9449710C9449710C9420 -58
2014.10.24 12:18:17.228 4: CUL_Parse: cul868 A 2C 44 00CA 1ACE1F 266E75 49710C94BC710C9449710C94B5760C94E3760C9449710C9449710C9449710C9449710C20 -58
2014.10.24 12:18:17.261 4: CUL_Parse: cul868 A 2C 44 00CA 1ACE1F 266E75 9449710C9449712E007061676553697A6520616E6420626C6F636B506F7320646966661F -58.5
2014.10.24 12:18:17.318 4: CUL_Parse: cul868 A 2C 44 00CA 1ACE1F 266E75 65720A00546F206D616E79206461746120666F72207061676553697A650A00626C6F6320 -58
2014.10.24 12:18:17.370 4: CUL_Parse: cul868 A 2C 44 00CA 1ACE1F 266E75 6B4C656E20646966666572207061676553697A650A0057726F6E67204D73674964210A20 -58
2014.10.24 12:18:17.406 4: CUL_Parse: cul868 A 2C 44 00CA 1ACE1F 266E75 0052657472616E736D69742C207265666C617368210A00476F74206F74686572206D7320 -58
2014.10.24 12:18:17.441 4: CUL_Parse: cul868 A 14 44 20CA 1ACE1F 266E75 67547970650A005265636520 -58

##################

die maximale Paketlänge sollte sich filtern lassen, indem das PKTLEN Register 0x06 des cc1101 benutzt wird. Siehe auch "15.3.2  Maximum Length Filtering" Im cc1101 datasheet. rf_asksin.c Änderung:

wenn ich das richtig sehe, wird zumindestens im file cc1100.c PKTLEN auf 61 byte begrenzt.

Code Auswählen Erweitern

const PROGMEM const uint8_t CC1100_CFG[EE_CC1100_CFG_SIZE] = {
// CULFW   IDX NAME     RESET STUDIO COMMENT
   0x0D, // 00 IOCFG2   *29   *0B    GDO2 as serial output
   0x2E, // 01 IOCFG1    2E    2E    Tri-State
   0x2D, // 02 IOCFG0   *3F   *0C    GDO0 for input
   0x07, // 03 FIFOTHR   07   *47   
   0xD3, // 04 SYNC1     D3    D3   
   0x91, // 05 SYNC0     91    91   
   0x3D, // 06 PKTLEN   *FF    3D   

scheinbar ein default von STUDIO (Atmel Studio?), was auch zur empfehlung im "RXFIFO_OVERFLOW Issue" passt.
dann würde ich sogar behaupten, dass die maximale länge unter hmip auch aus diesem "default" resultiert.

In applications where the packets are short enough to fit in the RX FIFO and one wants
to wait for the whole packet to be received before starting to read the RX FIFO, for
variable packet length mode (PKTCTRL0.LENGTH_CONFIG=1) the PKTLEN register
should be set to 61 to make sure the whole packet including status bytes are 64 bytes or
less (length byte (61) + 61 payload bytes + 2 status bytes = 64 bytes) or PKTLEN ≤ 62 if
fixed packet length mode is used (PKTCTRL0.LENGTH_CONFIG=0). In application
where the packets do not fit in the RX FIFO, one must start reading the RX FIFO before
it reaches its limit (64 bytes).

##################

Und was sind die eindeutigen Merkmale zur Unterscheidung in den 3 Bytes?

ich habe mal begonnen, die ersten 3 byte meiner empfangenen hmip messages zu sammeln. bisher sieht die liste sehr überschaulich aus. allerdings empfange ich hier auch nur sehr selten hmip, eventuell aus wohnmobilen.

Code Auswählen Erweitern

12 0083
10 008E
10 018E
00 008F
01 008F
bei diesem asksinpp projekt wird das 3. byte zur hmip erkennung untersucht.
"typeInt >= 0x80" ist aber falsch, da hier mindestens noch die typen 0xCA und 0xCB für das firmware update fehlen.
https://github.com/psi-4ward/AskSinAnalyzerXS/blob/master/app/src/SnifferParser.ts

Code Auswählen Erweitern

function getType(typeInt: number) {
  if (typeInt == 0x00) return "DEVINFO";
  else if (typeInt == 0x01) return "CONFIG";
  else if (typeInt == 0x02) return "RESPONSE";
  else if (typeInt == 0x03) return "RESPONSE_AES";
  else if (typeInt == 0x04) return "KEY_EXCHANGE";
  else if (typeInt == 0x10) return "INFO";
  else if (typeInt == 0x11) return "ACTION";
  else if (typeInt == 0x12) return "HAVE_DATA";
  else if (typeInt == 0x3E) return "SWITCH_EVENT";
  else if (typeInt == 0x3F) return "TIMESTAMP";
  else if (typeInt == 0x40) return "REMOTE_EVENT";
  else if (typeInt == 0x41) return "SENSOR_EVENT";
  else if (typeInt == 0x53) return "SENSOR_DATA";
  else if (typeInt == 0x58) return "CLIMATE_EVENT";
  else if (typeInt == 0x5A) return "CLIMATECTRL_EVENT";
  else if (typeInt == 0x5E) return "POWER_EVENT";
  else if (typeInt == 0x5F) return "POWER_EVENT_CYCLIC";
  else if (typeInt == 0x70) return "WEATHER";
  else if (typeInt >= 0x80) return "HMIP_TYPE";
  return "";
}

zusätzlich gibt es noch eine spezielle hmip message mit 6 bytes länge, die nur 2 geräteadressen (hmid) enthält.
das könnte das "kurze telegramm" sein (dunkelblau), das auf seite 10 des eq3-pdf zu finden ist. da der "reine" hmip burst auf 869mhz gesendet wird, ist das kurze telegramm eventuell auf 868mhz die entsprechende info zum burst.

[noansi]

Hallo Frank,

ich habe ein altes FUP (HM-LC-SW1PBU-FM, alternative fw über hmusb mit eq3 software) gefunden mit 46 bytes.

Danke für die Info. War fast zu erwarten, dass es ein Gegenbeispiel gibt.

wenn ich das richtig sehe, wird zumindestens im file cc1100.c PKTLEN auf 61 byte begrenzt.

Was aber für HM nichts bringt, weil in rf_asksin_init vor dem Schreiben der Konfiguration ein Reset des cc1101 ausgeführt wird und damit der Default von 255 wieder in dem Register landen sollte.

In SlowRF bringt es auch nichts, weil dabei gar kein Paket Handling stattfindet.

dann würde ich sogar behaupten, dass die maximale länge unter hmip auch aus diesem "default" resultiert.

Kann ich mir auch vorstellen.

ich habe mal begonnen, die ersten 3 byte meiner empfangenen hmip messages zu sammeln. bisher sieht die liste sehr überschaulich aus. allerdings empfange ich hier auch nur sehr selten hmip, eventuell aus wohnmobilen.

In der Tat übersichtlich. 

"typeInt >= 0x80" ist aber falsch, da hier mindestens noch die typen 0xCA und 0xCB für das firmware update fehlen.

Sehe ich auch so, bis auf die um Faktor 10 höheren Datenrate, mit der die beiden bei FUP gesendet werden.

Ist Bit 7=1 beim "HMTyp" für IP gesichert oder nur nicht anders beobachtet?
Siehe meine obige Fehlerfahrung zu FUP bei der Länge...

zusätzlich gibt es noch eine spezielle hmip message mit 6 bytes länge, die nur 2 geräteadressen (hmid) enthält.

In der tsculfw wir das schon durch Prüfung des Lenght Byte auf Mindestlänge 9 gefiltert. Also auch in culfw sehr einfach einbaubar.

Gruß, Ansgar.