Hallo pah,
ich betreibe einen Denkovi 1w Busmaster an einem Bus mit vier DS1820 Temperatursensoren.
Das läuft immer ein paar Tage stabil bis ein Disconnect des OWX IODev (Ursache noch ungeklärt) zu folgendem Fehlerbild führt:
OWX Logfile:
2021-01-25_23:48:11 denkovi_OWio DISCONNECTED
2021-01-26_08:36:39 denkovi_OWio CONNECTED <--- set denkovi_OWio reopen
2021-01-29_10:13:40 denkovi_OWio DISCONNECTED
2021-01-31_10:07:17 denkovi_OWio CONNECTED <--- set denkovi_OWio reopen
FHEM Logfile:
2021.01.25 23:48:11 1: /dev/ttyUSB97 disconnected, waiting to reappear (denkovi_OWio)
2021.01.25 23:48:11 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
2021.01.25 23:49:11 1: OWX_Init called for bus denkovi_OWio with interface state opened, now going for detect
2021.01.25 23:49:11 1: Cannot init /dev/ttyUSB97, ignoring it (denkovi_OWio)
2021.01.25 23:49:12 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
2021.01.25 23:49:17 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
2021.01.25 23:49:18 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
2021.01.25 23:49:21 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
2021.01.25 23:49:22 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
2021.01.25 23:49:25 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
...
Ein manueller "reopen" bereinigt die Situation wieder:
2021.01.26 08:36:39 1: /dev/ttyUSB97 reappeared (denkovi_OWio)
2021.01.26 08:36:39 3: OWX_Set denkovi_OWio reopen => 0
Wieso verbleibt OWX_SER nach einem Disconnect im State "opened" ? Wird dadurch ein automatischer "reopen" verhindert?
Danke & VG
Tobias
PS: alle OWX Module auf aktuellem Stand, hier noch ein List des OWX-Device:
fhem> list denkovi_OWio
Internals:
ALARMED no
ASYNCHRONOUS 1
BUSY 0
DEF /dev/ttyUSB97
DeviceName /dev/ttyUSB97
FD 190
FUUID 60045015-f33f-2a6d-19af-3851e8a1b9adc789
INITDONE 1
INTERFACE
LASTSEND 1612088398.10724
NAME denkovi_OWio
NR 687
PARTIAL
PRESENT 0
ROM_ID FF
STATE opened
TYPE OWX
interval 300
timeout 2
DEVHASH:
OWX_10_CC858D020800 10.CC858D020800.7D
denkovi_OWio Busmaster
hz_ds_RL 10.638C8D020800.F6
hz_ds_VL 10.9B618D020800.13
hz_ds_WW 10.FF818D020800.D6
DEVS:
10.CC858D020800.7D
10.638C8D020800.F6
10.9B618D020800.13
10.FF818D020800.D6
QUEUE:
READINGS:
2021-01-31 11:19:57 queue 2
2021-01-31 10:07:17 state opened
Attributes:
asynchronous 1
comment /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_DAE06Kth-if00-port0
room OWX
verbose 3
Hallo pah,
ich habe jetzt mal einen Blick in den Code von 11_OWX_SER.pm geworfen und habe die u.g. Fehlermeldung zum ersten Mal in Zeile 518 gefunden. Der Block sieht aber fast so aus, als wäre er versehentlich _nicht_ ausdokumentiert??
...
#if( $numget >= $numexp){
# main::Log3 $name, 4, "OWX_SER::Query $name: $numget of $numexp bytes in 2nd attempt and state $state";
# return $buffer;
#-- ultimate failure
#}else{
main::Log3 $name, 1,"OWX_SER::Query $name: $numget of $numexp bytes in last attempt and state $state, this is an unrecoverable error";
main::DevIo_Disconnected($hash);
main::InternalTimer(main::gettimeofday()+$timeout, "main::OWX_Ready", $hash,0);
return "";
#}
#--reopen device
main::Log3 $name, 4, "OWX_SER::Query $name: trying to close and open the device";
#-- the next two lines are required to avoid a deadlock when the remote end
# closes the connection upon DevIo_OpenDev, as e.g. netcat -l <port> does.
main::DevIo_CloseDev($hash);
main::DevIo_OpenDev($hash, 0, undef);
#-- second try to read things - with timeout
#$buffer .= main::DevIo_SimpleReadWithTimeout($hash, $timeout);
$buffer .= main::DevIo_SimpleRead($hash);
$numget = (defined($buffer))?length($buffer):0;
...
Nach meinem Verständnis führt doch das in Zeile 521 stehende "return" genau dazu, daß der folgende "reopen" und zweite Versuch zum Lesen der Daten eben nicht mehr ausgeführt wird.
Oder irre ich mich?
Danke & Gruß
Tobias
Öh. Stimmt. Ich kann mich nicht erinnern, wann und warum die Auskommentierung da hineingekommen ist :(
Sehr peinlich.
Der ursprüngliche Code hatte schon seinen Sinn, sonst hätte ich ihn ja nicht geschrieben...
Allerdings läuft das Modul bei mir astrein, ohne disconnects.
Was tut sich denn mit dem Denkovi, wenn die Auskommentierung weg ist?
LG
pah
Hallo pah,
danke für die Bestätigung. Ich habe jetzt mal den ganzen Block auskommentiert, sodaß der Code für reopen und zweiten Versuch beim Lesen bei Fehler greifen kann.
Natürlich ist seither noch kein "disconnect" wieder aufgetreten...
Was mir aber außerdem noch aufgefallen ist. Nach dem Editieren der 11_OWX_SER habe ich einen reload des Moduls gemacht:
fhem> reload 11_OWX_SER
Undefined subroutine &main::OWX_SER_Initialize called at fhem.pl line 2661.
Bei mir läuft folgende Version von fhem.pl
fhem.pl 23471 2021-01-04 19:24:21Z rudolfkoenig
Zeile 2661 ist in folgendem Block in der Funktion CommandReload:
...
# Get the name of the initialize function. This may differ from the
# filename as sometimes we live on a FAT fs with wrong case.
my $fnname = $m;
foreach my $i (keys %main::) {
if($i =~ m/^(${m})_initialize$/i) {
$fnname = $1;
last;
}
}
&{ "${fnname}_Initialize" }(\%hash);
$m = $fnname;
return undef;
Ich bin mir jetzt nicht sicher, ob das wirklich ein Problem ist, oder ob ein reload bei 11_OWX_SER als zweistufiges Modul einfach keine gute Idee ist.
VG
Tobias
Zitatreload bei 11_OWX_SER als zweistufiges Modul einfach keine gute Idee ist.
So ist es.
Mal abwarten,was sich tut.
LG
pah
Zitat von: Prof. Dr. Peter Henning am 06 Februar 2021, 07:21:55
Mal abwarten,was sich tut.
Heute gab es wieder zwei Abbrüche tagsüber - hier die Auszüge aus dem FHEM-Log:
Disconnect 1:
2021.02.07 10:02:33 1: /dev/ttyUSB97 disconnected, waiting to reappear (denkovi_OWio)
2021.02.07 10:02:33 1: OWX_SER::DEBUG 1 - pre reopen
2021.02.07 10:02:33 1: OWX_SER::DEBUG 2 - after reopen
2021.02.07 10:02:33 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at ./FHEM/11_OWX_SER.pm line 541.
2021.02.07 10:02:33 1: OWX_SER::DEBUG 3 - pre giveup
2021.02.07 10:02:33 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
==> manuell: set denkovi_OWio reopen:
2021.02.07 10:16:15 1: /dev/ttyUSB97 reappeared (denkovi_OWio)
2021.02.07 10:16:15 3: OWX_Set denkovi_OWio reopen => 0
2021.02.07 10:16:15 1: PERL WARNING: Use of uninitialized value in bitwise and (&) at ./FHEM/00_OWX.pm line 941.
Disconnect 2:
2021.02.07 12:42:34 1: /dev/ttyUSB97 disconnected, waiting to reappear (denkovi_OWio)
2021.02.07 12:42:34 1: OWX_SER::DEBUG 1 - pre reopen
2021.02.07 12:42:34 1: OWX_SER::DEBUG 2 - after reopen
2021.02.07 12:42:34 1: OWX_SER::DEBUG 3 - pre giveup
2021.02.07 12:42:34 1: OWX_SER::Query denkovi_OWio: 0 of 1 bytes in last attempt and state opened, this is an unrecoverable error
==> manuell: set denkovi_OWio reopen:
2021.02.07 15:02:13 1: /dev/ttyUSB97 reappeared (denkovi_OWio)
2021.02.07 15:02:13 3: OWX_Set denkovi_OWio reopen => 0
Log vom 1w OWX Busmaster:
2021-02-07_10:02:33 denkovi_OWio DISCONNECTED
2021-02-07_10:16:15 denkovi_OWio CONNECTED
2021-02-07_12:42:34 denkovi_OWio DISCONNECTED
2021-02-07_15:02:13 denkovi_OWio CONNECTED
Nur beim ersten Mal gab es noch die zwei Perl Warnings. Beide Male hat aber leider der unmittelbare "reopen" in der Routine query nicht geholfen. Vermutlich kommt dieser zu schnell. Zumindest wird jetzt aber die Meldung über den "unrecoveryble error" nur noch einmal ausgelöst und nicht wie vorher bei jedem Lesezugriff.
Wie vor der Modifikation auch hat ein späteres manuelles "set reopen" die Kommunikation wieder korrekt aufgesetzt.
Ich hänge unten noch die gesamte von mir modifizierte Routine query an, damit Du die zusätzlich DEBUG-Zeilen nachvollziehen kannst.
VG
Tobias:
Routine query aus 00_OWX_SER.pm:
sub Query ($$) {
my ($self,$cmd,$numexp) = @_;
my $hash = $self->{hash};
my $name = $hash->{NAME};
my $state = $hash->{STATE};
my $timeout = $hash->{timeout};
my $numget = 0;
my $buffer = "";
my $try;
if($state ne "opened") {
main::Log3 $name, 4, "OWX_SER::Query $name: attempted to write to $state device $name";
return undef;
}
#-- write operation
main::OWX_WDBGL($name,5,"OWX_SER::Query $name: Sending out",$cmd);
return undef unless defined(main::DevIo_SimpleWrite($hash, $cmd, 0));
#-- sleeping for some time
select(undef,undef,undef,0.04);
#-- first try to read things
$buffer = main::DevIo_SimpleRead($hash);
$numget = (defined($buffer))?length($buffer):0;
#-- first try ok
if( $numget >= $numexp){
main::Log3 $name, 4, "OWX_SER::Query $name: $numget of $numexp bytes in first attempt and state $state";
return $buffer;
#-- several tries to read from slow device
}elsif( ($numget>0) && ($numget<$numexp) ){
for($try=0;$try<3;$try++) {
$buffer .= main::DevIo_SimpleRead($hash);
$numget = length($buffer);
last
if( $numget>=$numexp );
select(undef,undef,undef,0.01);
}
main::Log3 $name, 5, "OWX_SER::Query $name: $numget of $numexp bytes in attempt $try and state $state"
if( $numget < $numexp );
return $buffer
if( $numget >= $numexp);
}
#if( $numget >= $numexp){
# main::Log3 $name, 4, "OWX_SER::Query $name: $numget of $numexp bytes in 2nd attempt and state $state";
# return $buffer;
#-- ultimate failure
#}else{
# main::Log3 $name, 1,"OWX_SER::Query $name: $numget of $numexp bytes in last attempt and state $state, this is an unrecoverable error";
# main::Log3 $name, 1,"OWX_SER::DEBUG 1";
# main::DevIo_Disconnected($hash);
# main::InternalTimer(main::gettimeofday()+$timeout, "main::OWX_Ready", $hash,0);
# main::Log3 $name, 1,"OWX_SER::DEBUG 2";
# return "";
# main::Log3 $name, 1,"OWX_SER::DEBUG 3";
#}
main::Log3 $name, 1,"OWX_SER::DEBUG 1 - pre reopen";
#--reopen device
main::Log3 $name, 4, "OWX_SER::Query $name: trying to close and open the device";
#-- the next two lines are required to avoid a deadlock when the remote end
# closes the connection upon DevIo_OpenDev, as e.g. netcat -l <port> does.
main::DevIo_CloseDev($hash);
main::DevIo_OpenDev($hash, 0, undef);
main::Log3 $name, 1,"OWX_SER::DEBUG 2 - after reopen";
#-- second try to read things - with timeout
#$buffer .= main::DevIo_SimpleReadWithTimeout($hash, $timeout);
$buffer .= main::DevIo_SimpleRead($hash);
$numget = (defined($buffer))?length($buffer):0;
#-- second try ok
if( $numget >= $numexp){
main::Log3 $name, 4, "OWX_SER::Query $name: $numget of $numexp bytes after reopening and state $state";
return $buffer;
#-- several tries to read from slow device
}elsif( ($numget>0) && ($numget<$numexp) ){
for($try=0;$try<4;$try++) {
$buffer .= main::DevIo_SimpleRead($hash);
$numget = length($buffer);
last
if( $numget>=$numexp );
select(undef,undef,undef,0.01);
}
main::Log3 $name, 5, "OWX_SER::Query $name: $numget of $numexp bytes in 2nd attempt try $try and state $state"
if( $numget < $numexp );
}
if( $numget >= $numexp){
main::Log3 $name, 4, "OWX_SER::Query $name: $numget of $numexp bytes in 2nd attempt and state $state";
return $buffer;
#-- ultimate failure
}else{
main::Log3 $name, 1,"OWX_SER::DEBUG 3 - pre giveup";
main::Log3 $name, 1,"OWX_SER::Query $name: $numget of $numexp bytes in last attempt and state $state, this is an unrecoverable error";
main::DevIo_Disconnected($hash);
return "";
}
}
OK, wird allerdings in den beiden nächsten Wochen nichts mit dem Einbau.
LG
pah
Hallo Tobias,
auf meinem Raspberry lief nun seit ca. 8 Jahren fhem mit dem one-wire USB Interface problemlos. Seit kurzem habe ich aber auch immer häufiger disconnects. Nach einem kürzlichen Update von fhem funktioniert leider auch das re-connect nicht mehr.
Zunächst möchte ich allerdings erstmal schauen woher das häufige disconnect kommt, das über Jahre hinweg niemals aufgetaucht ist. Da ich an der Raspberry- und Fhem- Konfiguration seit Jahren nichts geändert habe frage ich mich ob es evtl and dem USB-serial-onewire Stick liegen kann.
Weist du inzwischen woher die disconnects bei dir kommen?
Danke und Gruß, Holger
Zitat von: soho24 am 11 Februar 2021, 21:18:40
Weist du inzwischen woher die disconnects bei dir kommen?
Zuallererst - über einen langen Zeitraum habe ich den gleichen 1w-Bus an einem wemos01 mit ESPeasy betrieben und bin erst vor kurzem auf den Denkovi Bus Master an USB umgestiegen, um die nicht 100% zuverlässige WLAN Verbindung im Keller zu eliminieren.
Reproduzieren kann ich die disconnects nicht - allerdings könnten sie an meinem speziellen Setup liegen:
1wire-Bus --> Denkovi 1w Adapter -> ttyUSB auf RPi -> ser2net -> LAN -> Odroid hc1 -> socat -> ttyUSB -> OWX(_SER) (FHEM)
Wieso socat, wo pah doch in der CommandRef zu OWX (TCP) ausdrücklich erwähnt, daß es nicht erforderlich ist?
Anfangs hatte ich große Probleme, daß die DS1820 Temperatursensoren überhaupt von OWX gesehen wurden. Meine ersten Versuche, den Busmaster am entfernten RPi über ser2net mittels OWX (TCP) direkt anzusprechen, schlugen komplett fehl. Mit korrekter ser2net Parametrisierung (9600 Bit/s, 8N1) hat sich dann zwar OWX (TCP) mit dem Busmaster verbunden, jedoch eben keine 1w Devices gefunden. Darauß schloß ich (fälschlicherweise), daß die direkte OWX (TCP) Verbindung über den Umweg ser2net nicht funktioniert. Anschließend habe ich mit genausowenig Erfolg die obige Variante mit socat getestet, aber ebenfalls keine Devices gefunden.
Nach weiteren fehlgeschlagenen Tests mit dem Denkovi mit einem einzelnen DS1820 und dem Original Maxim OneWireViewer direkt am Windows Laptop war ich kurz davor, den Busmaster als defekt auszusortieren. Dann erst ist mir der via Jumper zuschaltbare RC Filter aufgefallen. Der DS1820 wurde weder in Jumper Stellung RC Filter on noch off gefunden. Sehr wohl aber nach kompletten Entfernen (!!) des Jumpers ...
Anschließend habe ich den Adapter wieder an den ursprünglichen 1w Bus angeschlossen - und prompt hat OWX (SER) via ser2net / socat alle angeschlossenen DS1820 gefunden... Froh darüber habe ich an die ursprüngliche Idee - ohne socat - direkt OWX (TCP) zu verwenden gar nicht mehr gedacht.
Lange Rede kurzer Sinn - zwischenzeitlich habe ich wie folgt vereinfacht:
1wire-Bus --> Denkovi 1w Adapter -> ttyUSB auf RPi -> ser2net -> LAN -> Odroid hc1 -> OWX(_TCP) FHEM
Das läuft jetzt seit einigen Tagen stabil.
@pah - das erklärt sicher auch, daß mein oben beschriebenes Problem bei dir nie aufgetreten ist.
VG
Tobias
Zitat1wire-Bus --> Denkovi 1w Adapter -> ttyUSB auf RPi -> ser2net -> LAN -> Odroid hc1 -> socat -> ttyUSB -> OWX(_SER) (FHEM)
Viel komplizierter geht es nicht - wie ziehst Du Dich morgens an? 8)
LG
pah
Zitat von: Prof. Dr. Peter Henning am 14 Februar 2021, 17:03:10
Viel komplizierter geht es nicht - wie ziehst Du Dich morgens an? 8)
Darum habe ich es ja jetzt radikal vereinfacht ;D
Nein, im Ernst, am gleichen remote Pi hängt auch noch ein Arduino Nano, welcher mittels ArduCounter Sketch den Gas- und Wasserzähler ausliest. Dieses serielle Device reiche ich ebenfalls per ser2net und socat an den FHEM Rechner mit dem ArduCounter Modul weiter. Rock solid...
VG
Tobias
Hallo zusammen,
Ich möchte das Thema mal wieder hochbringen...
Ich hatte auch ein viele Jahre stabil laufende Installation mit 1-Wire, habe dann mein Raspberry Pi mal neu aufgesetzt und danach fiel mir auf, dass die 1-Wire Anbindung nicht stabil läuft.
Ich kann die Beobachten die meine Vorposter beschrieben haben bestätigen.
- die Werte der Sensoren werden nicht aktualisiert, das Interface steht noch auf ,,opened" aber es können keine Sensoren mehr gelesen werden.
- wenn ich in diesem Zustand anzeigen lasse, welche Devices am Bus sind, bekomme ich keine angezeigt.
- ich kann den Fehler provozieren, wenn ich einen Sensor abfrage der nicht am Bus vorhanden ist.
- mit einem reopen kann ich es wieder temporär ,,heilen".
Kann ich mit weiteren Informationen helfen?
Viele Grüße Michael
Hallo zusammen,
Was ich gestern vergessen habe zu erwähnen.
- ich hatte bisher einen USB 1Wire Adapter von Fuchs, den hatte ich in der Vergangenheit immer direkt am RaspberryPi hängen gehabt.
- ich habe den Adapter auch schon über einen aktiven USB Hub versorgt.
- ich habe mir einen neuen 1Wire USB Adapter nach der Anleitung von PAH gebaut.
Alles das führt zum selben Ergebnis.
Wenn ich per dmesg nachsehe, bleibt das USB Device verbunden, sonst wäre ja auch ein set reconnect nicht erfolgreich wenn das USB Device ,,weg" wäre...
Viele Grüße Michael
Keine Ahnung - meine 5 1-Wire Busse, alle mit OWX, laufen stabil.
Davon 4x USB, einer an einem alten CUNO.
LG
pah