Autor Thema: CUL HM empfängt nicht oder sendet Empfangsdaten nicht an den Rechner  (Gelesen 15599 mal)

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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):

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:

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:
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.
« Letzte Änderung: 04 Mai 2014, 19:15:32 von noansi »

Offline Puschel74

  • Hero Member
  • *****
  • Beiträge: 9793
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.
« Letzte Änderung: 04 Mai 2014, 18:35:12 von Puschel74 »
Zotac BI323 als Server mit DBLog
CUNO für FHT80B, 3 HM-Lan per vCCU, RasPi mit CUL433 für Somfy-Rollo (F2F), RasPi mit I2C(LM75) (F2F), RasPi für Panstamp+Vegetronix +SONOS(F2F)
Ich beantworte keine Supportanfragen per PM! Bitte im Forum suchen oder einen Beitrag erstellen.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
- 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 :)

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
Hallo Rudolf,

Zitat
- 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.




Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
Zitat
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
Hallo Rudolf,

vielen Dank für den Tipp mit dem watchdog.

Ich habe seit gestern Abend einen watchdog:

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

Im Log tauchen nun 2 Einträge auf:

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.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
Zitat
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
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?

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Zitat
################################################
# 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();

Zitat
  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};
#
# 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;
}
}
}

Zitat
    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.

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

Zitat
  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)) {

# 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;
}

Zitat
      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.


Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
- 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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
Hallo Rudolf,

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

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.


Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

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.
« Letzte Änderung: 11 Mai 2014, 13:45:13 von noansi »

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

--- ./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:

Zitat
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

Zitat
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:

Zitat
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:

Zitat
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.


Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
Hallo CUL Programmier Experten,

nun das Ergebnis des Loggens vor und nach dem Disconnect:

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.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
Zitat
Wird beim erneuten Öffnen der Schnittstelle der Transceiver neu initialisiert und erholt sich dadurch wieder?
Ja, evtl.

Zitat
Bedeutet das, das der CUL eine Macke hat?
Evtl.

Zitat
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.

Zitat
Den RasPi kann ich nun wohl als Ursache ausschließen, denke ich.
Und worauf genau beruht diese Behauptung?

Zitat
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Zitat
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:

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

Und noch einen weiteren Abschnitt zum FSCAL1 Register:

Zitat
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.

Offline Jens_B

  • Full Member
  • ***
  • Beiträge: 328
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
RaspberryPi 3 (Raspian Stretch)FHEM+Homebridge
HMLAN für Homematic
Z-Wave USB Stick
Pilight
Fritz!Box 7490

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline Jens_B

  • Full Member
  • ***
  • Beiträge: 328
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
RaspberryPi 3 (Raspian Stretch)FHEM+Homebridge
HMLAN für Homematic
Z-Wave USB Stick
Pilight
Fritz!Box 7490

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

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.
« Letzte Änderung: 23 Mai 2014, 00:36:43 von noansi »

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

Zitat
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:

Zitat
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.
« Letzte Änderung: 25 Mai 2014, 22:46:36 von noansi »

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
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

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

Zitat
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.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
Zitat
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.


Zitat
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.

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375
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.

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:

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
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

--- 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:

#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.
« Letzte Änderung: 27 Mai 2014, 23:22:12 von noansi »

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
Zitat
Wäre schön, wenn Du das Speichertechnisch für CUL_V2 mal checken könntest.

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.

Offline martinp876

  • Developer
  • Hero Member
  • ****
  • Beiträge: 10233
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

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375

@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
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
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.

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375
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
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 18805
Wenn RSSI weiterhin hinten drangehaengt wird, dann nicht.

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375
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:

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 ?

# $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
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.
« Letzte Änderung: 01 Juni 2014, 17:07:32 von noansi »

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375
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.

Zitat
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.

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               

Zitat
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...

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
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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:

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


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


Gruß, Ansgar.
« Letzte Änderung: 05 Juni 2014, 00:26:55 von noansi »

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375
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.

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
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375
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.
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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

Offline tpm88

  • Full Member
  • ***
  • Beiträge: 375
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:

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:

# 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
Test FHEM Server on RPi, CUL_HM
Prod FHEM Server on CubieTruck, HM-USB, JeeLink
DB Logging FHEM Server on QNAP NAS
Devices: diverse HM, IT1500, 1wire via AVR NetIO, LaCrosse

Offline noansi

  • Sr. Member
  • ****
  • Beiträge: 581
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.

 

decade-submarginal