Mir ist leider beim letzten Netzausfall wieder aufgefallen, dass die blockierenden DNS Abfragen in HttpUtils_NonblockingGet ein riesengrosses Problem sind.
Bei mir ist FHEM dank genügend Calls dann komplett blockiert.
Ungünstig ist, dass es in der aktuellen Implementierung nicht nur eine, sondern 2 Stellen sind die jeweils 10 Sekunden Timeout haben, was damit zu je 20 Sekunden Blockade je Aufruf führt.
Zitatif($hash->{callback}) { # Nonblocking staff
$hash->{conn} = IO::Socket::INET->new(Proto=>'tcp', Blocking=>0);
if($hash->{conn}) {
my $iaddr = inet_aton($host);
if(!defined($iaddr)) {
my @addr = gethostbyname($host); # This is still blocking
return "gethostbyname $host failed" if(!$addr[0]);
$iaddr = $addr[4];
}
Ich finde hier braucht es eine Idee um dieses Problem zu verhindern oder zumindest abzuschwächen.
Hat jemand vielleicht schon eine?
Spontane Einfälle:
Check im Modul vor jedem Call (verbraucht aber auch 10 Sekunden) und dann hochsetzen der jeweiligen Timer
Globaler DNS Status der aus den Modulen abgefragt wird
Check in HttpUtils, evtl. mit interner Statusliste
Fällt jemandem etwas Sinnvolles ein?
Viele Grüsse,
Markus
Bist du sicher, dass inet_aton sich blocken kann? Die soll nur eine IP-Adresse erkennen.
Moeglichkeiten, die fuer gethostbyname mir einfallen:
- gethostbyname in BlockingCall aufrufen, evtl. nach dem ersten Blockieren (reicht das?)
- es gibt ein ADNS Bibliothek (weiss jemand mehr darueber?) und ein Perl Wrapper: http://search.cpan.org/~salva/Net-ADNS-0.03/lib/Net/ADNS.pm
- DNS query in perl selbst implementieren, kann nicht so schwer sein :)
Die Nonblocking-Alternative in FHEM muss zunaechst optional sein.
Zitat von: rudolfkoenig am 12 Mai 2016, 17:44:11
Bist du sicher, dass inet_aton sich blocken kann? Die soll nur eine IP-Adresse erkennen.
Moeglichkeiten, die fuer gethostbyname mir einfallen:
- gethostbyname in BlockingCall aufrufen, evtl. nach dem ersten Blockieren (reicht das?)
- es gibt ein ADNS Bibliothek (weiss jemand mehr darueber?) und ein Perl Wrapper: http://search.cpan.org/~salva/Net-ADNS-0.03/lib/Net/ADNS.pm
- DNS query in perl selbst implementieren, kann nicht so schwer sein :)
Die Nonblocking-Alternative in FHEM muss zunaechst optional sein.
inet_aton blockiert definitiv für 10 Sekunden, das passiert jetzt in meiner Fallback Lösung (leider je Device), siehe unten.
Im Prinzip müsste der Check global geschehen und weitere Versuche unterbinden bzw. den Modulen passendes Feedback geben - auch die Reduktion auf 10 Sekunden bringt nichts wenn die Module weiter blind Anfragen senden oder sie wie bei Twilight mehrfach wiederholen.
Meine nächste Idee wäre ein inet_aton mit variablem Timeout für Checks im Modul gewesen, ich will aber keine zusätzlichen Perl Libs.
Betroffen sind aktuell Twilight, Weather, Calendar, withings, netatmo, livetracking und allergy und wahrscheinlich noch weitere Module die ich bei mir nicht verwende.
Ich hab bei allergy (und allen anderen betroffenen Modulen) mal testweise folgendes eingebaut und rufe es vor jedem Call auf:
sub allergy_GetNetwork($) {
my ($hash) = @_;
my $name = $hash->{NAME};
my $resolve = inet_aton("www.allergiedaten.url");
if(!defined($resolve))
{
InternalTimer( gettimeofday() + 10800, "allergy_GetNetwork", $hash, 0);
return undef;
}
allergy_GetUpdate($hash);
return undef;
}
Das blockiert immer noch 10 Sekunden, allerdings dann nur alle paar Stunden. So ganz glücklich bin ich damit aber nicht.
Wenn ich bei zig Netatmo Geräten von 15 Minuten auf eine Stunde gehe, kommt eben immer noch einige Zeit zusammen in der FHEM blockiert ist.
Ohne diese Checks tut sich bei mir allerdings gar nichts mehr.
Gruss, Markus
inet_aton konvertiert einen string in die interne binäre adresse. in der meisten dokumentation steht zwar das es die string repräsentation einer ip4 adresse (also xxx.yyy.zzz.abc) erwartet aber tatsächlich akzeptiert es auch ganz normale host namen wie localhost aber auch www.google.de. die namensauflösung geht dann über den konfigurierten resolver. kann also blockieren.
gethostbyname macht zum teil das gleiche, einer der haupt unterschiede ist das mehr als eine adresse zurück liefern kann. ansonsten kann der aufruf auch blockieren.
ich bin mir nicht ganz sicher warum überhaupt beides aufgerufen wird bzw. in welchem fall inet_aton fehl schlägt und dann gethostbyname funktioniert.
ich weiss nicht wie effizient es ist für jeden das call zu forken wie es mit BlockigCall der fall wäre.
ADNS schaut gut aus. ich habe es noch nicht verwendet. man müsste mal schauen was intern genau passiert. es ist eventuell effizienter als BlockingCall. der aufwand es einzubauen und zu verteile ist aber vermutlich höher.
vielleicht kann man auch umgekehrt vorgehen: die namensauflösung in einen wrapper zu stecken der erst mal alles macht wie bisher, aber nach dem ersten blockieren ein flag setzt und jede weiter das anfrage verwirft. gleichzeitig per BlockigCall im hintergrund prüfen bis es wieder geht und dann das flag zurück setzen.
damit wäre der overhead im normalfall recht klein und man müsste auch nicht alles intern umbauen damit es mit einer non-blocking routine zurecht kommt. dafür nimmt man aber ein ein maliges blockieren für 10 sekunden in kauf.
unabhängig von der non-blocking frage: wäre es nicht sinnvoll auf die neuen inet_pton und/oder getaddrinfo umzusteigen wenn hier etwas angefasst? gethostbyname und inet_aton sind beide glaube ich schon als veraltet eingestuft.
Zitat von: justme1968 am 12 Mai 2016, 18:43:45ich bin mir nicht ganz sicher warum überhaupt beides aufgerufen wird bzw. in welchem fall inet_aton fehl schlägt und dann gethostbyname funktioniert.
Mir fällt spontan keiner ein.
Zitatvielleicht kann man auch umgekehrt vorgehen: die namensauflösung in einen wrapper zu stecken der erst mal alles macht wie bisher, aber nach dem ersten blockieren ein flag setzt und jede weiter das anfrage verwirft. gleichzeitig per BlockigCall im hintergrund prüfen bis es wieder geht und dann das flag zurück setzen.
damit wäre der overhead im normalfall recht klein und man müsste auch nicht alles intern umbauen damit es mit einer non-blocking routine zurecht kommt. dafür nimmt man aber ein ein maliges blockieren für 10 sekunden in kauf.
Klingt gut und die 10 Sekunden wären ok.
Soll das dann je Hostname passieren? Es kann ja theoretisch auch mal vorkommen dass der Hostname aus einem Aufruf nicht aufgelöst werden kann, alle anderen aber funktionieren.
Zitatich bin mir nicht ganz sicher warum überhaupt beides aufgerufen wird
Ich schon: ich war bisher der Ansicht, dass inet_aton nur die String-Representation der 4-stelligen IP-Adresse zu der binaeren Variante konvertiert. Ich schau die Geschichte am Wochenende mal naeher an.
gerade über den thread gestolpert, war duch Zufall vergangene Woche mit genau dem Thema beschäftigt.
Das aton blocken kann überrascht mich auch gerade, da war ich definitiv auch der Meinung das der nicht und nur gethosbyname blockt. Wenn Rudi das prüft ist das top.
Für DNS habe ich auch nur ADNS gefunden (auch bei intensiver Suche), war aber nicht so glücklich weil man wieder neue cpan module beim user vorraussetzt.
Ich habe kurz über eine eigene Implementierung nachgedacht. Das cpan Modul ist recht mächtig, macht hallt auch Zonentransfer, mmx und so weiter. Das brächte man ja für einen gethostbyname nicht. Das habe aber dann verworfen weil ich keinen guten Weg gefunden habe den defaullt System DNS einfach zu bekommen.
Schlßendlich habe ich das dann in einen fork gesteckt. Das ist aber auch nicht optimal.. Wenn halt mehrere Abfragen parallel benötigt werden, zum Beispiel bei Start, dann wird für jeden ein fork aufgemacht und wenn der DNS nicht da ist (darum gehts ja hauptsächlich) hat man plötzlich einige dutzend forks offen.
Bin auch noch nicht recht glücklich so, klinke mich sehr gern hier mit ein.
vg
joerg
das aton nicht nur numerische ip adressen akzeptiert findet man sogar in der doku wenn man lange genug sucht. es fängt mit beispielen an in denen localhost verwendet wird und dann steht sogar was von fully qualified hostnamen drin.
lässt sich mit inet_aton('www.google.de') auch ganz einfach überprüfen.
genau wegen den vielen forks der vorschlag die logik umzudrehen. und nur im fehlerfall ein mal zu forken. damit ist zwar alles nicht wirklich non-blocking sondern man riskiert genau ein mal zu blockieren. aber eben nur für x sekunden und auch nur ein mal. und man muss nicht den ganzen code auch auf non-blockeng und callbacks umstellen.
gruss
andre
Na klar, wirst recht haben. In den docs wird es so stehen.
Den block der bei aton rauskommt müsste man doch für ip auch händisch bauen können. Schau ich mir heute abend mal an.
Vg
Joerg
Ich habe HttpUtils.pm erweitert:
- Namensaufloesung fuer nonblocking nach HttpUtils_gethostbyname ausgelagert
- falls eine IPV4 Adresse spezifiziert ist, dann wird keine DNS-Routine aufgerufen, sondern pack()
- falls "attr global dnsServer" _nicht_ gesetzt ist dann wird gethostbyname aufgerufen, inet_aton ist entfernt.
- falls "attr global dnsServer" gesetzt ist (auf dem DNS-Server, am besten IP-Adresse), dann wird nicht blockierend via UDP nachgefragt, und das Ergebnis bis TTL gecached.
Ist natuerlich alles IPV4, der Rest der Routinen ist aber auch noch nicht IPV6 faehig.
Habs mit meinem fritz.box und mit 8.8.8.8 getestet, scheint zu tun.
dnsServer dokumentiere ich erst dann, wenn ich mehr Feedback kriege.
Augefallen ist mir bisher, dass CNAME Records bei gesetzten dnsServer Atrribut nicht berücksichtigt werden:
Error: DNS: Wrong answer for ...
Hallo zusammen,
ich würde dann mit eurem OK den Hinweis im Wiki zum Thema DNS-Auflösung bei HttpUtils_NonblockingGet() entfernen.
http://www.fhemwiki.de/wiki/HttpUtils#HttpUtils_NonblockingGet
Gruß
Markus
@dev0: kannst du bitte in HttpUtils.pm die Zeile mit "DNS ANSWER" aktivieren, und die Ausgabe im Fehlerfall hier anhaengen?
@Markus: im Prinzip ja, ich moechte aber mehr Feedback haben (s.o.), bevor ich das als "verwendbar" deklariere.
Kein Thema. Ich beobachte das ganze eh mit ;-)
Gruß
Markus
sehr geile Lösung !!! :D
vg
joerg
DNS Answer zu einem CNAME (www.ddtlab.de):
2016.05.16 06:16:58.476 1: DNS ANSWER 277:70728580000100020003000603777777066464746c61620264650000010001c00c0005000100000000000603787878c010c02b0001000100000e1000040523f4e2c0100002000100000e10000f026e73076464746c61627302657500c0100002000100000e10000d026e73076464746c616273c017c0100002000100000e100010026e73076464746c616273036e657400c0680001000100000e1000040523f4e2c068001c000100000e1000102a010488006610000523f4e200000001c0810001000100000e1000046c3b0841c081001c000100000e10001026049a002010a0130001000000000001c04d0001000100000e1000045fd30191c04d001c000100000e10001020011af84400a0480001000000000001
www.ddtlab.de ist ein Alias für den canonical name xxx.ddtlab.de.
www.ddtlab.de. IN CNAME xxx.ddtlab.de.
xxx.ddtlab.de. IN A 5.35.244.226
@dev0: dein DNS Server ist wie die Politiker: beantwortet eine Frage, die man nicht gestellt hat.
Habe eine Version eingecheckt, die mit solchen Antworten besser umgehen kann.
Es gibt noch eine Merkwuerdigkeit mit inet_aton/gethostbyname hier (https://forum.fhem.de/index.php?topic=53406).
Ist mehr oder weniger eine standard bind 9.8 Installation, keine Fritzbox ;)
Die Adresse wird jetzt korrekt aufgelöst.
Ich habe leider nach wie vor das selbe Verhalten bei einem Netzausfall.
Also Blockieren wenn das Netz komplett weg ist und der DNS TTL überschritten ist.
Liegt das an meiner neu eingebauten DNS Aufloesung?
Wenn ja, dann bitte ein "attr global verbose 5" Log hier reinkleben.
Welche Logeinträge interessieren dich genau? Die zwei DNS?
global verbose 5 geht leider nicht, da reicht die Platte keine 10 Minuten für das Log.
Ich kann mal versuchen das zu simulieren, der Rechner muss dabei aber länger als die TTL offline sein.
Erstens will ich wissen, welche DNS Auflösung verwendet wird. Und dann Details in diesem Fall. Manche Module reichen ein loglevel weiter, in diesem Fall reicht es da verbose hochzudrehen.
Hallo,
kann es sein, dass HttpUtils_Err den callback mit dem falschen Hash aufruft (%dh) und dass dieser dann in der Sub, die von HttpUtils_Connect an HttpUtils_gethostbyname übergeben wird auch falsch an den Callback des aufrufenden Moduls geht?
Ich habe da eine Beschwerde eines HTTPMOD Anwenders, die ich mir nur so erklären kann ...
Gruss
Stefan
Ja, es kann sein, obwohl ich euer Problem nicht nachstellen kann.
Mit einem falsch gesetzten dnsServer Attribut habe ich ein "PERL WARNING: Deep recursion on anonymous subroutine at FHEM/HttpUtils.pm line 237" generiert. Das habe ich gerade behoben und eingecheckt. Kannst du bitte euer Problem mit der neuen Version pruefen?
Hallo,
ich kann das Problem leider auch nicht nachvollziehen, aber das Symptom ist dass HTTPMOD ewig auf die letzte Antwort wartet und weitere Requests in die Queue stellt. Das kann nur dann passieren wenn entweder der Callback gar nicht von HttpUtils augerufen wird oder wenn er mit einem falschen Hash aufgerufen wird. Deshalb habe ich nach einem potentiellen Bug gesucht.
Mit Deiner Änderung kann das nach meinem Verständnis nun nicht mehr passieren.
Gruss / Thanx
Stefan
Hallo nochmal,
inzwischen hat Ernst die Logs von einem neuen Blockade-Fall gepostet: https://forum.fhem.de/index.php/topic,45176.240.html
Daraus wird ersichtlich, dass der _Read Callback von HTTPMOD in seinem Fall gar nicht aufgerufen wird. Es muss also irgendwo noch ein Bug liegen. Ich bin etwas ratlos und es fällt mir auch schwer den Datenfluss bei HttpUtils mit den vielen Callbacks und Übergaben nachzuvollziehen.
Es wäre naheliegend ihm eine Spezialversion von HttpUtils mit vielen Log-Aufrufen zu geben, habe aber Skrupel inoffizielle Versionen von fremdem Code zu verteilen...
Ich könnte auch einen zu HttpUtils redundanten Timeout-Timer in HTTPMOD einbauen, aber das löst dann das eigentliche Problem nicht.
Ideen?
Gruss
Stefan
Ich habe jetzt einen weiteren Bug behoben, der allerdings "seit immer" vorhanden war: falls das nonblocking Connect sofort mit Fehler zurueckkommt, dann hat Nonblocking_Get return "Fehlermeldung" ausgefuehrt, statt den Callback aufzurufen. Das habe ich jetzt gefixt.
Reproduzieren kann man das, indem man Http_NonblockingGet in ca 4-Sekunden Rhythmus mit einem ausgeschalteten Rechner aufruft. In der "alten" Version werden manchmal die Callbacks nicht aufgerufen.
Ich gehe davon aus, dass das die Ursache des verlinkten Problems ist.
Wunderbar!
Jetzt müsste nur noch jemand das ganze auch für DevIO und Fhem2Fhem nutzbar machen ;-)
Gruss und vielen Dank
Stefan
Kannst du das bitte erklaeren?
Es wäre schön wenn DevIO und Fhem2Fhem ebenfalls einen nonblocking connect hätten. Im Prinzip steckt ein großer Teil der Arbeit dafür in HttpUtils schon drin. Früher oder später wird vermutlich jemand die dafür nötige Zeit finden und versuchen die Ideen für DevIO und Fhem2Fhem zu adaptieren. Ich habe mir das auch schon mal vorgenommen, aber ich finde leider momentan auch nicht die Zeit dafür. Ich bin schon froh wenn ich mit HTTPMOD am Ball bleiben kann und Modbus mal wieder erweitern kann. Euch wird es nicht anders gehen.
Jedenfalls wenn es jemand anpackt, dann wäre es doch naheliegend, die anderswo verwendbaren Funktionen wie HttpUtils_GetHostByName eher zu einem FhemGetHostByName zu machen. Vielleicht könnte man auch ein TCPUtils Modul aus einigen Funktionen von HttpUtils machen, so dass ein nonblocking Connect einfacher von anderen Modulen nutzbar wäre.
So einfach wie das jetzt klingt ist es sicher nicht aber eine so schöne Verbesserung beim GetHostByName verdient doch zumindest mittel- oder langfristig einen breiteren Einsatz ;-)
Gruß
Stefan
Die DevIo_OpenDev() Funktion sichert bisher zu, dass nach dem Aufruf die Verbindung zum Geraet steht. Man muesste also einen zusaetzlichen Callback spezifizieren, damit nonblocking Connect aufgerufen werden kann -> Ohne Aenderung im jeweiligen Modul gibt es kein nonblocking Connect.
Gibt es dafuer einen Bedarf?
Hallo,
ich denke der Mehrwert ist vor allem in den Ready-Funktionen beim Reconnect.
Wenn ein Gerät beim Starten von Fhem nicht erreicht werden kann, ist eine kurze Verzögerung vermutlich kaum ein Problem.
Wenn aber ein Gerät im laufenden Betrieb temporär nicht mehr erreichbar wird und dadurch Fhem regelmäßig beim Versuch die Verbindung wieder aufzubauen blockiert, wäre ein nonblocking Connect sehr hilfreich. Ich würde es zumindest in 98_Modbus.pm einbauen.
Gruss
Stefan
Ab sofort gibt es die Moeglichkeit in DevIo_OpenDev das nicht blockierende Http_Connect zu verwenden (was in diesem Fall nichts mit HTTP zu tun hat), wenn man einen 4. Parameter (den callback) spezifiziert.
Bisher:
my $ret = DevIo_OpenDev($hash, 0, "FBAHA_DoInit");
Falls jemand nonblocking connect will:
DevIo_OpenDev($hash, 0, "FBAHA_DoInit", sub(){
my ($hash, $err) = @_;
Log3 $name, 2, "$name: $err" if($err);
});
Die bisherige Variante bleibt natuerlich erhalten.
Sobald das optionale 4. Parameter spezifiziert ist, wird es immer aufgerufen, selbst wenn das (wie bei USB) synchron passiert. Sinnvoll ist es nur fuer TCP/IP, die Verbindung wird dann vom HttpUtils_Connect hergestellt (das ist Teil vom HttpUtils_NonblockingGet)
Fuer die bisherigen Faelle musste ich etwas Code umsortieren. Ich hoffe, dass ich dabei nichts uebersehen habe, trotzdem bitte ich alle, etwas aufzupassen, und Probleme hier melden.
Hier scheint es ein Problem mit CUL/HM zu geben: https://forum.fhem.de/index.php/topic,54839.0.html (https://forum.fhem.de/index.php/topic,54839.0.html)
HttpUtils_NonblockingGet hat(te) das Problem, dass sie nicht funktioniert, wenn direkt nach dem Aufruf blockierender Kode laenger als das eingestellte Timeout (default 4s) ausgefuehrt wird. Das kann z.Bsp. bei der Initialisierung passieren, oder bei der Schaltung von vielen Geraeten, die jeweils fuer ein bisschen Blockierung sorgen.
Um das Problem zu loesen habe ich eine globale Variable $selectTimestamp eingefuehrt (enthaelt den Zeitstempel vor dem select Aufruf), und die Routinen in Http_NonblockingGet versuchen anhand dieser Variable zu erkennen, ob es sich um das beschriebene Problem handelt. Das Verfahren ist nicht perfekt, wer ein Besseres hat, soll sich melden. Und falls jemandem ein Problem mit der Loesung auffaellt, der auch.
Ich habs für das ONKYO_AVR Modul jetzt mal zumindest für den initialen Verbindungsaufbau drin, funktioniert problemlos:
# connect using serial connection (old blocking style)
if ( $hash->{DeviceName} =~ m/^UNIX:(SEQPACKET|STREAM).*)$/
|| $hash->{DeviceName} =~ m/^FHEM:DEVIO:(.*)(.*))/ )
{
my $ret = DevIo_OpenDev( $hash, 0, "ONKYO_AVR_DevInit" );
return $ret;
}
# connect using TCP connection (non-blocking style)
else {
# add missing port if required
$hash->{DeviceName} = $hash->{DeviceName} . ":60128"
if ( $hash->{DeviceName} !~ m/^(.+)[0-9]+)$/ );
DevIo_OpenDev(
$hash, 0,
"ONKYO_AVR_DevInit",
sub() {
my ( $hash, $err ) = @_;
Log3 $name, 2, "ONKYO_AVR $name: $err" if ($err);
}
);
}
Für den Re-Connect in der ReadyFn bin ich mir jetzt nicht ganz sicher, ob dort die initFn tatsächlich fehlen darf?
sub ONKYO_AVR_Ready($) {
my ($hash) = @_;
if ( ReadingsVal( $hash->{NAME}, "state", "disconnected" ) eq
"disconnected" )
{
DevIo_OpenDev(
$hash, 1, undef,
sub() {
my ( $hash, $err ) = @_;
Log3 $name, 2, "ONKYO_AVR $name: $err" if ($err);
}
);
return;
}
# This is relevant for windows/USB only
my $po = $hash->{USBDev};
my ( $BlockingFlags, $InBytes, $OutBytes, $ErrorFlags );
if ($po) {
( $BlockingFlags, $InBytes, $OutBytes, $ErrorFlags ) = $po->status;
}
return ( $InBytes && $InBytes > 0 );
}
Ich bin gerade am Testen bzw. versuche zu verstehen, wie der DevIo_OpenDev mit TCP nonblocking zu verwenden ist. Folgendes kommt mir seltsam vor:
In DevIo_OpenDev im Callback für HttpUtils_Connect wird - falls $err gesetzt ist - kein doTcpTail aufgerufen. Damit wird auch NEXT_OPEN nicht gesetzt und beim ersten connect kommt auch nichts zur $readyfnlist hinzugefügt. Ist das ein Bug oder verstehe ich da noch was nicht?
Man könnte natürlich viele Dinge auch in die _Ready-Funktion der Module verlagern, aber da NEXT_OPEN ja schon existiert, wäre es ja eleganter wenn es auch verwendet wird.
Ab Zeile 330 in DevIo:
if($callback) {
use HttpUtils;
my $err = HttpUtils_Connect({ # Nonblocking
timeout => $timeout,
url => "http://$dev/", # not really http
NAME => $hash->{NAME},
noConn2 => 1,
callback=> sub() {
my ($h, $err, undef) = @_;
return $callback->($hash, $err) if($err);
# hier wird in kein doTcpTail aufgerufen wenn $err übergeben wurde
return &$doCb("") if(!&$doTcpTail($h->{conn}));
return &$doCb(&$doTailWork());
}
});
return &$doCb($err) if($err);
return undef;
} else {
my $conn = IO::Socket::INET->new(PeerAddr => $dev, Timeout => $timeout);
# hier wird in jedem Fall doTcpTail aufgerufen
return &$doCb("") if(!&$doTcpTail($conn));
}
Unabhängig davon: verstehe ich es richtig, dass ein Modul im Callback für DevIo_OpenDev prüfen sollte, ob bereits ein Open läuft und sich noch nicht zurückgemeldet hat? Sonst gibt es evt. viele parallele Opens ...
Gruss
Stefan
ZitatIst das ein Bug oder verstehe ich da noch was nicht?
War wohl Bug, habe die Aenderungen nicht auf reconnect getestet, danke fuer den Hinweis.
Habs geaendert, kurz getestet und eingecheckt.
ZitatUnabhängig davon: verstehe ich es richtig, dass ein Modul im Callback für DevIo_OpenDev prüfen sollte, ob bereits ein Open läuft und sich noch nicht zurückgemeldet hat? Sonst gibt es evt. viele parallele Opens ...
Ja, da es auch richtig gebaute Server gibt, die mehrere parallele Anfragen verkraften oder sogar wuenschen.
Vielen Dank!
Jetzt fehlt noch ein Aufruf von doCB falls NEXT_OPEN noch nicht erreicht ist.
Zudem wäre es jetzt schön wenn das aufrufende Modul die NEXT_OPEN Verzögerung beeinflussen könnte.
Ein Patch-Vorschlag anbei.
Was (optisch) noch nicht ganz optimal ist, ist das jetzt entstehende Logging von den HttpUtils bzw. dessen Rückmeldungen an den Callback.
2016.06.30 20:54:48 3: aaModTest: Open callback: connect to http://192.168.70.148:502 timed out
2016.06.30 20:55:08 4: HttpUtils url=http://192.168.70.148:502/
vielleicht könnte man HttpUtils_Connect noch so erweitern, dass beim Aufruf durch DevIo kein Http:// vorangestellt werden muss und dass damit die Meldungen von den HttpUtils auch kein Http:// mehr enthalten?
Man könnte natürlich auch den reinen TCP-Connect aus HttpUtils herauslösen.
Gruss
Stefan
ZitatJetzt fehlt noch ein Aufruf von doCB falls NEXT_OPEN noch nicht erreicht ist.
Davon bin ich noch nicht ueberzeugt: warum ist das notwendig?
Weiterhin wird die Funktion ohne Fehlermeldung aufgerufen, das "fuehlt" sich nicht richtig an.
ZitatZudem wäre es jetzt schön wenn das aufrufende Modul die NEXT_OPEN Verzögerung beeinflussen könnte.
Diese Aenderung habe ich uebernommen und eingecheckt.
ZitatWas (optisch) noch nicht ganz optimal ist, ist das jetzt entstehende Logging von den HttpUtils bzw. dessen Rückmeldungen an den Callback.
Stimmt, das stelle ich aber erst um, wenn das Ganze "gereift", und verwendet wird.
Hallo,
ich hatte mir die Schnittstelle bisher so "zusammengereimt", dass der Callback ähnlich wie bei den HttpUtils auf jeden Fall aufgerufen wird und dass das aufrufende Modul daran erkennt, dass der Verbindungsversuch zum Ende gekommen ist.
Wenn das nicht so gedacht ist, dann bräuchte das aufrufende Modul ein anderes Erkennungsmerkmal um zu wissen ob es noch auf einen callback "warten" soll bzw. ob es weitere Verbindungsversuche zurückstellen soll oder nicht.
Die _Ready-Funktion hatte ich bisher so angedacht:
sub Modbus_OpenCB($$)
{
my ($hash, $msg) = @_;
my $name = $hash->{NAME};
Log3 $name, 3, "$name: Open callback: $msg" if ($msg);
delete $hash->{BUSY_OPENDEV};
}
sub Modbus_Ready($)
{
my ($hash) = @_;
my $name = $hash->{NAME};
return if ($hash->{BUSY_OPENDEV}) # still waiting for callback to last open
if($hash->{STATE} eq "disconnected") {
$hash->{BUSY_OPENDEV} = 1;
return DevIo_OpenDev($hash, 1, 0, \&Modbus_OpenCB);
}
...
}
Ohne eine Art BUSY_OPENDEV würde die _Ready-Funktion unter Umständen (hängt dann vom Timing und der Wartezeit für NEXT_OPEN ab) mehrere redundante Verbindungsversuche auslösen. Zusätzlich würde ich vermutlich auch noch einen zweiten Timeout einbauen, damit BUSY_OPENDEV nicht ewig gesetzt bleibt wenn mal etwas nicht funktioniert.
Gruss
Stefan
Die Verbindung ist in diesem Fall weder endgueltig schiefgegangen, noch gelungen, deswegen wollte ich mir den Callback sparen. Sonst gibt einer eine Fehlermeldung aus, oder versucht was zu uebertragen, und beides ist ja falsch.
Falls man nur eine Verbindung haben will, dann muss man den Flag vor dem Open setzen, und nicht im callback, sonst erzeugen 2 Userlevel-Aufrufe (define/set/get/etc) auch bei schnell reagierende Gegenstelle zwei Verbindungen: Open ist nicht blockierend.
Hallo,
jetzt kann ich leider nicht folgen.
Dass Open nicht blockiert, war ja das Ziel. Der Callback, der im hash an HttpUtils_Connect übergeben wird, wird doch aufgerufen wenn entweder die Verbindung aufgebaut wurde oder wenn der Verbindungsaufbau gescheitert ist und eine Fehlermeldung an den Callback übergeben wird.
Entsprechend dachte ich dass der Callback, der bei DevIo_OpenDev übergeben wird, ebenfalls aufgerufen werden soll, wenn entweder die Verbindung erfolgreich aufgebaut wurde, oder wenn es nicht geklappt hat. Nach dem Aufruf von DevIo_Opendev selbst ist aber noch alles offen.
Habe ich bis hier schon etwas falsch verstanden?
Gruss
Stefan
Nein, aber wir diskutieren ueber den Fal, wo FHEM versucht die Verbindung weiterhin (periodisch) zu oeffnen. Aus Modulsicht ist der Vorgang nicht abgeschlossen, also weder gescheitert, noch gelungen.
Falls der Code dein Modbus_OpenCB aufrufen wuerde, obwohl in einer Minute der zweite Open-Versuch stattfindet, denn waere BUSY_OPENDEV zu unrecht entfernt.
ok, dann haben wir offenbar aneinander vorbei geredet.
So lange Fhem das Modul / Gerät auf der readyfnlist hat, wird die _Ready-Funktion immer wieder aufgerufen. Eventuell sogar im Sekundentakt. Das wollte ich nicht anzweifeln und daran wollte ich mit einem BUSY_OPENDEV auch nichts ändern.
Es geht mir um folgenden Fall:
Es wird nur eine TCP Verbindung vom Modul zu einem Modbus-Gerät benötigt.
die Verbindung geht verloren, das Gerät kommt auf die readyfnlist.
_Ready ruft DevIo_OpenDev mit einem Callback auf um die Verbindung nonblocking wieder herzustellen.
Fhem wartet jetzt quasi parallel auf das Herstellen der Verbindung und das kann ein paar Sekunden dauern.
In der Zwischenzeit wird die _Ready-Funktion schon wieder aufgerufen.
_Ready ruft DevIo_OpenDev nochmals auf, obwohl der erste Call noch gar nicht fertig bearbeitet wurde und noch kein Timeout gegriffen hat.
Damit das nicht vorkommt würde ich in der _Ready-Funktion erst dann wieder DevIo_OpenDev aufrufen, wenn der letzte Versuch tatsächlich schon gescheitert ist.
Deshalb wollte ich vor dem Aufruf von DevIo_OpenDev ein BUSY-Flag setzen und dieses erst dann wieder löschen wenn der aktuelle Verbindungsversuch sich zurückgemeldet hat. Entweder mit Fehler / Timeout oder mit Success. Im Fehlerfall wird dann beim nächsten Aufruf von _Ready ein neuer Versuch gestartet. Aus Modulsicht bleibt in der Zeit das Device auf disconnected und logisch quasi im Zustand "Reconnect-Versuch". Nur die überschneidenden Aufrufe von DevIo_Opendev aus der _Ready-Funktion wollte ich so verhindern.
Daher mein Wunsch, dass das Modul in allen Fällen ein Rückmeldung per Callback bekommt, damit das temporäre BUSY-Flag gelöscht werden kann und so der nächste Verbindungsversuch gestartet werden kann.
Gruss
Stefan
Die Loesung ist mAn einfach: man setzt vor dem ersten DevIo_OpenDev ein Flag. Sobald der Flag gesetzt ist, wird kein zweites DevIo_OpenDev versucht, bzw. erst dann, wenn der erste endgueltig gescheitert ist.
Noch einfacher ist es, falls eine staendige Verbindung sinnvoll ist: Define/ReadyFn oeffnet die Verbindung, und WriteFn schreibt nur dann, falls die Verbindung existiert. Falls sie nicht existiert, kann man die Daten sammeln, oder einen Fehler melden.
Zitat
Die Loesung ist mAn einfach: man setzt vor dem ersten DevIo_OpenDev ein Flag. Sobald der Flag gesetzt ist, wird kein zweites DevIo_OpenDev versucht, bzw. erst dann, wenn der erste endgueltig gescheitert ist.
Genau so würde ich das gerne machen. Die Frage, an der ich nicht weiter komme ist:
Wann ist der erste Verbindungsversuch endgueltig gescheiter?
Nach Aufruf von DevIo_OpenDev ist ja noch alles offen, da es nicht blockiert.
Der Callback wird in den meisten Fällen von DevIo_OpenDev aufgerufen, aber eben nicht in allen Fällen.
Wenn wie bei NEXT_OPEN der Callback nicht aufgerufen wird, weiss ich nicht woran ich erkennen kann, ob der letzte Verbindungsversuch noch läuft ...
Gruss
Stefan
ZitatWann ist der erste Verbindungsversuch endgueltig gescheiter?
Die Reihenfolge sollte sein:
- aus dem moduleigenen DefineFn/etc wird DevIo_OpenDev aufrufen
- Verbindungsaufbau geht schief
- DevIo_OpenDev aktiviert readyfnlist
- Callback wird aufgerufen, meldet Fehler
- das Modul-Eigene ReadyFn wird regelmaessig aufgerufen, hier wird DevIo_Opendev auch aufgerufen.
- wenn die Verbindung klappt, wird der callback (aus diesem ReadyFn-DevIo_Opendev) aufgerufen
- wenn nicht, wird nichts aufgerufen.
Falls das nicht der Fall ist, dann bitte melden.
Zitat
Zitat
Zitat
Die Loesung ist mAn einfach: man setzt vor dem ersten DevIo_OpenDev ein Flag. Sobald der Flag gesetzt ist, wird kein zweites DevIo_OpenDev versucht, bzw. erst dann, wenn der erste endgueltig gescheitert ist.
Genau so würde ich das gerne machen. Die Frage, an der ich nicht weiter komme ist:
Wann ist der erste Verbindungsversuch endgueltig gescheitert?
Die Reihenfolge sollte sein:
- aus dem moduleigenen DefineFn/etc wird DevIo_OpenDev aufrufen
- Verbindungsaufbau geht schief
- DevIo_OpenDev aktiviert readyfnlist
- Callback wird aufgerufen, meldet Fehler
- das Modul-Eigene ReadyFn wird regelmaessig aufgerufen, hier wird DevIo_Opendev auch aufgerufen.
- wenn die Verbindung klappt, wird der callback (aus diesem ReadyFn-DevIo_Opendev) aufgerufen
- wenn nicht, wird nichts aufgerufen.
Falls das nicht der Fall ist, dann bitte melden.
Da sind wir wieder an dem Punkt: wenn (im Fehlerfall) nichts aufgerufen wird, wie bekommt das Modul dann mit dass der letzte Verbindungsversuch endgültig gescheitert ist um daraufhin das Flag zu löschen, so dass beim nächsten Aufruf der Modul-eigenen ReadyFn von dort aus wieder DevIo_OpenDev aufgerufen werden darf?
In der Reihenfolge, die Du gerade beschrieben hast, kommt das mit dem Flag nicht mehr vor.
Auch wenn die Verbindung nicht aufgebaut wird oder im Fehlerfall wird ja bisher schon in fast allen Fällen der Callback aufgerufen:
Zeile 250:
if($hash->{DevIoJustClosed}) {
delete $hash->{DevIoJustClosed};
return &$doCb(undef);
}
Zeile 341:
return &$doCb($err ? $err : &$doTailWork());
oder ausserhalb des TCP-Bereichs in Zeile 267:
if($@) {
Log3 $name, 1, $@;
return &$doCb($@);
}
Daher fände ich es nur konsequent wenn auch in Zeile 306 der Callback aufgerufen würde. Das würde mein Problem lösen - ich könnte im Callback das Flag löschen und es würde der Programmlogik des obigen Fragments (ab Zeile 250) entsprechen.
if($hash->{NEXT_OPEN} && time() < $hash->{NEXT_OPEN}) {
return undef;
# hier würde ich mir genauso wie oben bei if($hash->{DevIoJustClosed}) statt dem einfachen return einen Aufruf des Callback wünschen:
# return &$doCb(undef);
}
Ich hoffe ich konnte mein Anliegen doch noch verständlich erklären.
Gruss
Stefan
Nicht wirklich, ich habe dein Wunsch aber trotzdem eingecheckt, da (wie du es gezeigt hast) das Verhalten auch an anderen Stellen inkonsequent ist, und mir die Zeit/Energie/Lust fehlt, alles auf "sauber" umzubauen.
Hallo Rudi,
die aktuell in SVN vorhandene Version der DevIo.pm sorgt zuverlässig dafür, dass mein fhem nicht mehr startet.
Mit der Version
DevIo.pm 11732 2016-07-02 17:41:31Z rudolfkoenig
ist alles wieder in bester Ordnung.
Ich fuerchte, wenn ich nicht mehr Details kriege, wird es dabei bleiben.
Ok, dann musst Du es eben morgen fixen, wenn nach dem morgendlichen Update (vorhersehbar) noch mehr Leute ein nicht mehr funktionierendes fhem haben. Aber sag dann bitte nicht, Du hättest nichts gewußt 8)
Das System startet, läuft kurze Zeit, stürzt dann ab (ohne dass im Logfile etwas aussergewöhnliches zu erkennen wäre) und landet in der automatischen restart-Schleife von systemd. Dann beginnt das Spiel von vorne.
Ich kann Dir heute leider nicht mehr Details zum Problem liefern, ausser, dass ich das Verhalten heute abend auf drei verschiednenen fhem Installationen hatte, die mit der neusten Version von DevIo.pm arbeiteten. Nach dem Downgrade der Datei auf die angegebene Vorgängerversion liefen alle drei Systeme wieder.
Zitat von: betateilchen am 05 Juli 2016, 22:10:53
Ok, dann musst Du es eben morgen fixen, wenn nach dem morgendlichen Update (vorhersehbar) noch mehr Leute ein nicht mehr funktionierendes fhem haben.
q.e.d.
https://forum.fhem.de/index.php/topic,55332.0.html
Zitat von: rudolfkoenig am 06 Juli 2016, 13:38:12
Das Problem kam dann, wenn ein per TCP/IP angebundenes Geraet nicht erreichbar war.
Habs vermutlich jetzt gefixt, ...
Hallo Rudi,
ich habe die Änderung nun auch hier erfolgreich getestet, danke.
Wobei ich den Punkt "ein per TCP/IP angebundenes Gerät" nicht nachvollziehen kann, da es auf meinem Entwicklungs-Raspberry ausser einer FHEMWEB und einer telnet Instanz keine anderen TCP/IP basierten Geräte gibt und der Fehler trotzdem auftrat.
Offenbar hatte fhem da eine Auto-Immunkrankheit und war mit sich selbst unverträglich :)
Ich muss das nochmal aufgreifen, auch wenn ich mich fast nicht traue. Irgendwas stimmt immer noch nicht, FHEM2FHEM flutet mir den eventMonitor und das Logfile:
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:58 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:00:59 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
Vermutlich unnötig, zu sagen, dass mit der bereits erwähnten Version 11732 von DevIo.pm diese Meldungsflut nicht auftritt.
Waere ich zu frech, wenn ich ein Log-Ausschnitt mit einem hoeheren verbose-level haben wollte?
im Prinzip nicht, aber auch mit global verbose 5 und FHEM2FHEM-device verbose 5 läßt sich auch dem Logfile nicht viel mehr entlocken:
2016.07.07 14:44:46 3: FHEM2FHEM opening fhemenocean at 192.168.123.159:7172
2016.07.07 14:44:47 3: FHEM2FHEM device opened (fhemenocean)
2016.07.07 14:46:40 3: FHEM2FHEM opening fhemenocean at 192.168.123.159:7172
2016.07.07 14:46:48 3: FHEM2FHEM device opened (fhemenocean)
2016.07.07 14:49:39 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:49:39 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
2016.07.07 14:53:26 3: FHEM2FHEM opening fhemenocean at 192.168.123.159:7172
2016.07.07 14:54:31 1: FHEM2FHEM 192.168.123.159:7172 reappeared (fhemenocean)
Und ich konnte bisher auch die Flut nicht mehr reproduzieren, mehr als zwei Meldungen nacheinander tauchten nicht auf.
Interessanterweise scheint FHEM2FHEM aber kein Log zu schreiben, wenn eine Verbindung verschwindet.
Alles sehr eigenartig.
Das Problem gehoert hierher: https://forum.fhem.de/index.php?topic=55194
Hallo Rudi,
zunächst mal vielen Dank für das Einbauen des Callbacks bei NEXT_OPEN. Im Modbus-Modul habe ich es wie schon gepostet mit einem BUSY_OPENDEV eingebaut. Dabei ist mir aufgefallen, dass es noch eine Art Race Condition im DevIo_OpenDev gibt, die direkt in DevIo behebbar sein sollte.
Als ich testweise das BUSY_OPENDEV Flag weggelassen habe, und der Zielserver nicht existierte, ist einmal in der Minute eine ganze Sequenz von Open-Versuchen gestartet worden. Die Modbus_Ready-Funktion ist ca. 10 mal in der Sekunde aufgerufen worden und hat auch genauso oft DevIo_OpenDev aufgerufen.
Ich vermute, dass es daran liegt, dass NEXT_OPEN erst in doTcpTail gesetzt wird. DevIoOpenDev beendet dann und Fhem ruft gleich wieder Modbus_Ready auf, während der Open-Versuch noch läuft und der Timeout noch nicht erreicht ist.
Als Lösung würde ich NEXT_Open schon setzen wenn das Nonblocking Http_Connect abgesetzt wurde.
Für das Modbus-Modul ist das ganze erst mal kein Problem, da ich ja weitere Aufrufe von DevIo_Opendev in der Modbus_Ready-Funktion über ein eigenes Flag verhindere bis der Callback aufgerufen wurde.
Gruss
Stefan
Ich braeuchte das Problem genauer bzw. nachstellbar beschrieben, da ich das Problem nicht sehe, und ich ein Fix auch testen will.
Hallo,
anbei ein Test-Modul, das versucht eine TCP-Verbindung zu öffnen und ein Diff für DevIo, damit mehr geloggt wird.
Das Testmodul würde ich so einbinden:
define DevIoTest TCPTest 192.168.70.199:99
attr DevIoTest verbose 5
Die Adresse sollte dabei nicht existieren.
Im Log erscheint bei mir dann folgendes:
2016.07.11 21:00:25 3: DevIoTest: define with destination 192.168.70.199:99
2016.07.11 21:00:25 3: Opening DevIoTest device 192.168.70.199:99
2016.07.11 21:00:25 1: Including ./log/fhem.save
...
2016.07.11 21:00:34 3: Can't connect to 192.168.70.199:99:
2016.07.11 21:00:34 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:00:34 5: DevIoTest: _ready called
...
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:33 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:34 5: DevIoTest: _ready called
2016.07.11 21:01:34 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:34 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:35 5: DevIoTest: _ready called
2016.07.11 21:01:35 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:35 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:36 5: DevIoTest: _ready called
2016.07.11 21:01:36 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:36 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIo-Debug: calling HttpUtils_Connect
2016.07.11 21:01:37 4: HttpUtils url=http://192.168.70.199:99/
2016.07.11 21:01:37 5: DevIoTest: Open callback: connect to http://192.168.70.199:99 timed out
2016.07.11 21:01:37 5: DevIoTest: Open callback: connect to http://192.168.70.199:99 timed out
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: Open callback: 192.168.70.199: Keine Route zum Zielrechner
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
2016.07.11 21:01:37 5: DevIoTest: _ready called
Das interessante ist dabei dass ab 21:01:34 NEXT_OPEN vorbei ist und dann HttpUtils_Connect mehrfach aufgerufen wird.
Gruss
Stefan
Danke fuer das schoene Testprogramm. Die Anzahl der ReadyFn Aufrufe haengt von den restlichen Definitionen ab, in einer minimalen Testkonfiguration gab es nur einen doppelten Aufruf (immerhin). Liegt meiner Ansicht nach an dem zu spaet entfernten readyfnlist Eintrag, das habe ich jetzt geaendert, bitte um Feedback.
Sieht gut aus!
Gruß und Thanx
Stefan
Hallo Rudi,
ich habe Deine DNS Query in eigenen modulen adaptiert. Danke für die Vorlage!
Bei der Abfrage von api.geonames.org bekomme ich manchmal eine DNS Antwort wo der DNS Server in der Antwort nicht den offset aus der Frage verwendet sondern den Hostnamen in die Antwort schreibt. Beispiel:
a53881800001000600000000036170690867656f6e616d6573036f72670000010001036170690867656f6e616d6573034f52470000010001000001000004b009274fc0220001000100000100000405099836c02200010001000001000004b23f5cf2c02200010001000001000004b0096ba9c02200010001000001000004bc282113c02200010001000001000004050929d0
Hier schlägt die Prüfung in httputils (#117) auf type und class fehl - die anderen Antworten findet er dann auch nicht mehr. Der DNS antwortet nur sporadisch so.
vg
joerg
ungetestet:
#160/161 umbauen in
my $bhost = join("", map { pack("CA*",length($_),$_) } split(/\./, $host)) . "\0x00";
my $qry = pack("nnnnnn", 0x7072,0x0100,1,0,0,0) . $bhost . pack("nn", 1,1);
in dnsParse dann test ql +1 and 0xC0 == 0 ist eine Name, dann geht es weiter bei ql + length(bhost) sonst ql + 2.
Ergänzend könnte man zur Sicherheit noch ql +1 eq bhost testen, wobei der DNS dann irgendwas anderes antworten würde. Weiß nicht ob das vorkommen kann (CNAME wird ja eigentlich anders behandelt).
vg
joerg
Hallo joerg,
dein Aenderungsvorschlag verwirrt mich: fuegt das 0-Byte nicht in der zweiten sondern in der ersten Zeile zu qry hinzu.
Habs nicht uebernommen.
Dein Beispiel enthaelt nicht komprimierte DNS Daten, das scheint heutzutage die Ausnahme zu sein, und wurde bisher von HttpUtils_dnsParse nicht verstanden. Eine verstaendliche Erklaerung des Formats habe ich nur hier (http://www.ccs.neu.edu/home/amislove/teaching/cs4700/fall09/handouts/project1-primer.pdf) gefunden, und danach implementiert. Nach meinen Tests scheint es zu funktionieren, sowohl mit deinen unkomprimierten Daten, wie auch mit "normalen" Antworten. Falls jemand einen DNS-Server kennt, der immer unkomprimiert antwortet, dann moege er das bitte hier melden.
Gruss,
Rudi
alles gut. Die Änderung die Du eingecheckt hast sollte es tun.
vg
joerg