gelöst [DevIo/00_CUL] störung/ausfall der cul verbindung blieb unbemerkt

[frank]

moin.

mein cul868 im homematic mode konnte scheinbar irgendwann nicht mehr mit fhem kommunizieren, was in 00_CUL aber leider nicht registriert wurde. der state war weiterhin auf initialized.

den ausfall des cul habe ich nur zufällig bemerkt, da es im fhem.log keine CUL_Parse einträge mehr gab, obwohl
beim cul zufällig verbose=5 gesetzt war. also keine "lebenszeichen" vom cul in fhem.

ab dem letzten CUL_Parse konnte ich dann auch erkennen, dass alle sendebefehle an den cul nicht mehr "on air" gingen, da weitere gateways diese funkmessages nun nicht mehr registrierten.
alle befehle an den cul wurden quasi ignoriert.

log ausschnitte vor und nach dem ausfall:

Code Auswählen Erweitern

##### letzter fhem start vor dem ausfall
2022.08.24 13:03:57.868 3: Opening cul868 device /dev/serial/by-id/usb-busware.de_CUL868-if00
2022.08.24 13:03:57.924 3: Setting cul868 serial parameters to 38400,8,N,1
2022.08.24 13:03:58.033 3: cul868: Possible commands: BCFiAZEGMKURTVWXefmltux
2022.08.24 13:03:58.040 3: cul868 device opened
2022.08.24 13:03:58.047 2: Switched cul868 rfmode to HomeMatic


##### letzte 3 CUL_Parse einträge vor dem ausfall. besonderheit: der letzte eintrag ist eine kopie des dritt-letzten
2022.08.27 16:02:37.608 4: CUL_Parse: cul868 A 0B D7 A258 B2B2B2 1DFC2F 00FD2E -51
2022.08.27 16:02:37.610 5: cul868: dispatch A0BD7A258B2B2B21DFC2F00FD::-51:cul868

2022.08.27 16:02:37.739 4: CUL_Parse: cul868 A 0E D7 8202 1DFC2F B2B2B2 0101C6002127 -54.5
2022.08.27 16:02:37.741 5: cul868: dispatch A0ED782021DFC2FB2B2B20101C60021::-54.5:cul868

2022.08.27 16:02:37.774 4: CUL_Parse: cul868 A 0B D7 A258 B2B2B2 1DFC2F 00FD2E -51
2022.08.27 16:02:37.775 5: cul868: dispatch A0BD7A258B2B2B21DFC2F00FD::-51:cul868

##### direkt danach sieht senden über cul im log normal aus, aber die messages gehen nicht mehr on air
2022.08.27 16:02:37.856 5: cul868 sending As0A7480021ACE1F1C1BE300
2022.08.27 16:02:37.857 5: CUL 1C1BE3 dly:38ms
2022.08.27 16:02:37.897 5: DevIo_SimpleWrite cul868: As0A7480021ACE1F1C1BE300


##### manuelles reopen lieferte opened im cul state
2022.08.28 16:50:36.671 3: Setting cul868 serial parameters to 38400,8,N,1
2022.08.28 16:50:36.784 5: DevIo_SimpleWrite cul868: V
2022.08.28 16:50:39.790 5: DevIo_SimpleWrite cul868: V
2022.08.28 16:50:42.795 5: DevIo_SimpleWrite cul868: V
2022.08.28 16:50:45.800 1: Cannot init /dev/serial/by-id/usb-busware.de_CUL868-if00, ignoring it (cul868)

##### ebenfalls erfolgloser fhem restart liefert auch opened
2022.08.28 17:00:38.881 3: Opening cul868 device /dev/serial/by-id/usb-busware.de_CUL868-if00
2022.08.28 17:00:38.937 3: Setting cul868 serial parameters to 38400,8,N,1
2022.08.28 17:00:48.054 1: Cannot init /dev/serial/by-id/usb-busware.de_CUL868-if00, ignoring it (cul868)
2022.08.28 17:00:48.058 2: Switched cul868 rfmode to HomeMatic


wäre es möglich beim cul einen "alive-check" einzubauen?
schön wäre eine regelmässiger request an den cul, der ggf zu einem automatischen reopen führt.

wenn man zu solch einem "roundtrip" noch irgendwo die dauer des roundtrip sehen könnte, hätte man zusätzlich einen ungefähren anhaltspunkt über die "latenz" der verbindung.

[mi.ke]

Man könnte als interimslösung auch die CUL_TIME in den Internals in einem bestimmen Interval abfragen und bei einer größeren Abweichung eine Nachricht generieren oder eben ein reopen ausführen lassen.

cheers
mi.ke

[yersinia]

Ich überwache stündlich (über ein at) diverse Gerätetypen und bei den CULs versuche ich dann drei mal ein reopen (via ein paar perl zeilen in der myutils). Insbesondere dem alten bootloader hatte ich öfters Ausfälle aka Hängen des Arduinos, seitdem ich TSCUL und SIGNALduino nutze treten die Probleme nicht mehr auf. Schau doch mal, ob der CUL ein Reading oder Internal hat, was sich regelmässig ändert. Ansonsten kannst du zB auch version oder uptime abfragen, da fällt es auf, wenn es keine Antwort gibt.

[rudolfkoenig]

Ich wuerde mit einem at die Zeit der letzten Kommunikation (gespeichert im Internal cul868_TIME) auswerten, evtl gekoppelt mit regelmaessiger Abfrage der Version.

Ein Nebeneffektfreies alive-check ist bei der aktuellen Architektur (CUL.pm und culfw) aufwendig, und ich bin noch nicht ueberzeugt, dass der Umbau sich lohnt.

[frank]

dieser spezielle fall:

- kein empfang
- kein senden
- kommunikation zwischen fhem und cul ohne probleme

war scheinbar ein sporadisches PLL_NO_LOCK problem, das seit culfw 1.59 gelöst ist.

seit update meiner culfw 1.58 auf 1.67 wurden 2 dieser ereignisse registriert und automatisch beseitigt.


dafür gibt es nun leider ein neues problem:
https://forum.fhem.de/index.php?topic=137450.0

[pipp37]

Ich wuerde mit einem at die Zeit der letzten Kommunikation (gespeichert im Internal cul868_TIME) auswerten, evtl gekoppelt mit regelmaessiger Abfrage der Version.

Hallo. Da ich kürzlich auf einen MaxCube mit  geflashter a-culfw für WMBUS und Homematic umgestiegen bin, bekam FHEM einen kurzen Ausfall der Maxcube nicht mit und blieb immer initialized und keine Daten kamen an.

Ich habe darum ein AT erstellt welches genau die CUL_TIME  auf Änderungen  prüft und nach 3 erfolglosen Checks 5* versucht, ein REOPEN zu machen.

Gruss Armin


Die Variablen müssen auf den entsprechenden CUL angepasst werden. Auch die Zeit (alle 1 Minuten) ändern.

# after x failures reopen
my $errorcnt=3;
# try reopen x times
my $tryreopen=5;

# check cul
my $chkCUL="cubeCUN2";
# check changing cul reading
my $chkReading="cubeCUN2_TIME";

Define:

Code Auswählen Erweitern

define cubeCUN2_chk_at at +*00:01:00 set x=1

Dann mit den dem internen Editor den Code einfügen.


Anbei das list eines meiner at devices.

Code Auswählen Erweitern

   DEF        +*00:01:00 {
# after x failures reopen
my $errorcnt=3;
# try reopen x times
my $tryreopen=5;

# check cul
my $chkCUL="cubeCUN2";
# check changing cul reading
my $chkReading="cubeCUN2_TIME";

my $prefix="chk_";
# get curtime internal
my $internaltime=InternalVal("$chkCUL","$chkReading","unknown");
# get last time
my $internaltimeLast=ReadingsVal("$chkCUL", "$prefix"."time_internal_last", "0");
my $reopencounter=ReadingsVal("$chkCUL", "$prefix"."reopen_counter", "0");
my $reopencountertry=ReadingsVal("$chkCUL", "$prefix"."reopen_counter_try", "0");

fhem("setReading $chkCUL $prefix"."time_internal $internaltime");

# check if time changed
if ("$internaltime" eq  "$internaltimeLast")
{ $reopencounter++;
  Log3("global",3,"DEBUG-AT:$chkCUL: Reading $chkReading not changed $reopencounter times! Device offline?");
  # reset reopencounter after 100 times
  if ($reopencounter > 100) {$reopencounter=0};  
  fhem("setReading  $chkCUL $prefix"."reopen_counter " . $reopencounter);
}
else
{ Log3("global",3,"DEBUG-AT:$chkCUL: Reading $chkReading changed. Device alive.");
  fhem("setReading $chkCUL $prefix"."time_internal_last $internaltime");
  if ($reopencounter>0)    {fhem("setReading $chkCUL $prefix"."reopen_counter 0")};
  if ($reopencountertry>0) {fhem("setReading $chkCUL $prefix"."reopen_counter_try 0")};
  $reopencounter=0;$reopencountertry=0;      
}

# reopen part
if ($reopencounter > $errorcnt)
{ $reopencountertry++;
  if ($reopencountertry < $tryreopen+1)
      { Log3("global",3,"DEBUG-AT:$chkCUL: Try $reopencountertry/$tryreopen to reopen.");
    fhem("set $chkCUL reopen");
  }
  else
  { Log3("global",3,"DEBUG-AT:$chkCUL: Try reopen failed $tryreopen times. Abort reopen!");
    $reopencountertry=$tryreopen;
  }

   fhem("setReading  $chkCUL $prefix"."reopen_counter_try " . $reopencountertry);
}

}

   FUUID      6645271b-f33f-37ef-3475-5a484d4d8f7f19e4
   NAME       cubeCUN2_chk_at
   NR         6828
   NTM        14:17:05
   PERIODIC   yes
   RELATIVE   yes
   REP        -1
   STATE      Next: 14:17:05
   TIMESPEC   00:01:00
   TRIGGERTIME 1715861825.88127
   TRIGGERTIME_FMT 2024-05-16 14:17:05
   TYPE       at
   eventCount 874
   .attraggr:
   .attrminint:
   Helper:
     DBLOG:
       state:
         logdb:
           TIME       1715861766.07761
           VALUE      Next: 14:17:05
   READINGS:
     2024-05-16 14:16:06   state           Next: 14:17:05
Attributes:
   room       CUL
   verbose    1