FHEM Forum

FHEM => Anfängerfragen => Thema gestartet von: Jensc am 24 November 2019, 22:11:49

Titel: [Gelöst] "Connection refused" bei Blocking Call
Beitrag von: Jensc am 24 November 2019, 22:11:49
Hallo,
ich laufe beim DWD_OpenData auf ein Problem, bei dem ich nicht mehr weiter weiß: Bei einem get forecast kommt nach 30 Sek. die Meldung "forecast error: downloading and processing weather forecast data failed (Process died prematurely)", Readings werden nicht fegesetzt. Wenn man den Loglevel auf 5 setzt, kann man im Logfile folgendes finden:

2019.11.24 20:45:08 5: Cmd: >get Inf_Wetter forecast<
2019.11.24 20:45:08 5: Inf_Wetter: GetForecast START (PID 855)
2019.11.24 20:45:08 5: Starting notify loop for Inf_Wetter, 1 event(s), first is updating forecasts
2019.11.24 20:45:08 4: DbLog DBLogging -> number of events received: 1 for device: Inf_Wetter
2019.11.24 20:45:08 4: DbLog DBLogging -> check Device: Inf_Wetter , Event: state: updating forecasts
2019.11.24 20:45:08 5: DbLog DBLogging -> parsed Event: Inf_Wetter , Event: state: updating forecasts
2019.11.24 20:45:08 4: DbLog DBLogging -> added event - Timestamp: 2019-11-24 20:45:08, Device: Inf_Wetter, Type: DWD_OPENDATA, Event: state: updating forecasts, Reading: state, Value: updating forecasts, Unit:
2019.11.24 20:45:08 4: DbLog DBLogging -> processing event Timestamp: 2019-11-24 20:45:08, Device: Inf_Wetter, Type: DWD_OPENDATA, Event: state: updating forecasts, Reading: state, Value: updating forecasts, Unit:
2019.11.24 20:45:08 5: End notify loop for Inf_Wetter
2019.11.24 20:45:08 5: Inf_Wetter: GetForecast END
2019.11.24 20:45:08 4: WEB: /fhem?detail=Inf_Wetter&dev.getInf_Wetter=Inf_Wetter&cmd.getInf_Wetter=get&arg.getInf_Wetter=forecast&val.getInf_Wetter=&XHR=1&addLinks=1&fwcsrf=csrf_250484318321244&fw_id=1490 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip
2019.11.24 20:45:08 5: Inf_Wetter: GetForecastStart START (PID 1046): https://opendata.dwd.de/weather/local_forecasts/mos/MOSMIX_L/single_stations/10865/kml/MOSMIX_L_LATEST_10865.kmz
2019.11.24 20:45:09 5: Inf_Wetter: ProcessForecast START
2019.11.24 20:45:09 5: Inf_Wetter: ProcessForecast: data received, decoding ...
2019.11.24 20:45:09 5: Inf_Wetter: ProcessForecast: parsing XML document
2019.11.24 20:45:09 5: Inf_Wetter: ProcessForecast: extracting data
2019.11.24 20:45:09 5: Inf_Wetter: ProcessForecast temp file /tmp/oiKl6UtMO7 forecast 3 size 17753
2019.11.24 20:45:09 5: Inf_Wetter: ProcessForecast END
2019.11.24 20:45:09 5: Inf_Wetter: GetForecastStart END
2019.11.24 20:45:38 3: Inf_Wetter: GetForecastAbort error: downloading and processing weather forecast data failed (Process died prematurely)
2019.11.24 20:45:38 5: Starting notify loop for Inf_Wetter, 1 event(s), first is forecast error: downloading and processing weather forecast data failed (Process died prematurely)


Wenn man sich den Code durchschaut, sieht es für mich so aus, als würde der GetForecast sauber beendet, aber der BlockingCall läuft  auf GetForecastAbort und eben nicht auf GetForecastFinish.

Zur Umgebung: Raspberry Pi 3, in einem Container läuft pivccu3, zum Logging wird mariaDB mit DBLog verwendet.


  Operating System: Raspbian GNU/Linux 9 (stretch)
            Kernel: Linux 4.19.66-v7+
      Architecture: arm


forecastStation ist auf 10865 gesetzt (München Stadt)

Für Tipps wäre ich dankbar.

Workaround
Mit Hilfe von @CoolTux konnte ich das Problem umgehen (das nichts mit DWD_OpenData zu tun hat, sondern u.a. auch da auftritt). Wer keine Lust hat, den ganzen Thread durchzulesen, kann sich das Problem mit
define telnetPort telnet 7072 global
shutdown restart

vom Hals schaffen. Allerdings hat man dann einen offenen telnet Port am FHEM, was u.U. zu Sicherheitslücken führen kann. Einen Vorschlag, wie man das durch eine einfache Codeänderung beheben kann, habe ich am 16.12.2019 in diesem Thread gepostet, aber der kommt natürlich ohne Gewähr.
Wer das Problem auch hat, kann bitte in diesem Thread einen kurzen Kommentar hinterlassen. Wenn zehn Betroffene zusammengekommen sind, melde ich das als Wunsch an. (Und wenn noch jemand eine Idee hat, wo ich ins Betriebssystem fassen kann, darf sich auch gerne melden).
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 27 November 2019, 21:33:33
Mittlerweile bin ich einen Schritt weiter: Das Problem scheint bei den telnet Verbindungen zu liegen, die Blocking.pm aufbaut. Wenn ich die Tests aus Blocking.pm ausführe (TestBlocking(3)) erhalte ich auf Log Level 5 folgende Einträge:

2019.11.27 20:45:43 5: Cmd: >{TestBlocking(3)}<
2019.11.27 20:45:43 4: [b]BlockingCall (DoSleep)[/b]: created child (21533), uses telnetForBlockingFn_1574804640 to connect back
2019.11.27 20:45:43 4: WEB: /fhem&fw_id=101&room=ZZSystem&fwcsrf=csrf_172593289955663&cmd=%7BTestBlocking%283%29%7D / RL:1730 / text/html; charset=UTF-8 / Content-Encoding: gzip
/ Cache-Control: no-cache, no-store, must-revalidate

2019.11.27 20:45:43 1: [color=red]Connection refused from 192.168.178.56:51908[/color]
2019.11.27 20:45:43 4: WEB_192.168.178.36_62017 GET /fhem?XHR=1&inform=type=status;filter=;since=1574883942;fmt=JSON&fw_id=101×tamp=1574883943627; BUFLEN:0
2019.11.27 20:45:48 1: Aborted: AbortArg

Die Fehlermeldung taucht auch bei dem ursprünglichen Problem der DWD Anbindung auf. 192.168.178.56 ist die IP Adresse des raspi, auf dem FHEM läuft. Auf "list TYPE=telnet" bekomme ich folgende Konfiguration:
Internals:
   CFGFN     
   CONNECTS   28
   DEF        0
   FD         16
   FUUID      5ddd9ca0-f33f-18f0-10d6-5c08145c9a983719
   NAME       telnetForBlockingFn_1574804640
   NR         59
   PORT       34435
   STATE      Initialized
   TEMPORARY  1
   TYPE       telnet
   READINGS:
     2019-11-26 22:44:00   state           Initialized
Attributes:
   allowfrom  127.0.0.1
   room       hidden

Und falls ich sicherheitshalber einen update versuche, erscheint ebenfalls:
2019.11.27 21:31:11 1 : Connection refused from 192.168.178.56:53610
Insgesamt scheint also irgendetwas in der Konfiguration schief zu liegen, dass Blocking.pm nicht korrekt arbeiten kann. Hat jemand einen Tipp, wo ich suchen kann?

Nachtrag: Zumindest das ursprüngliche Problem von DWD_OpenData lässt sich eindeutig auf den BlockingCall zurück führen: Wenn man den Aufruf im Device selbst so hackt, dass er synchron erfolgt und nicht über BlockingCall, funktioniert die Abfragen der Wetterdaten (der update aber natürlich noch nicht). Also statt

$hash->{".forecastBlockingCall"} = ::BlockingCall("DWD_OpenData::GetForecastStart", $hash, "DWD_OpenData::GetForecastFinish", 30, "DWD_OpenData::GetForecastAbort", $hash);

den folgenden Zeilen einsetzen:
getForecastResult = GetForecastStart($hash);GetForecastFinish(@$getForecastResult);

und schon funktioniert die Abfrage der Wetterdaten. Ist IMHO aber eher ein ,,diagnostischer Hack" als eine echte Lösung des Problems.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 09:48:20
Mittlerweile konnte ich das Problem so weit identifizieren, dass es von einem einzeiligen Patch gelöst wird: In /opt/fhem/FHEM/Blocking.pm muss man die folgende Zeile in der Routine BlockingStart patchen (Ergänzungen in rot):
72:    $attr{$BC_telnetDevice}{allowfrom} = "127.0.0.1[color=red]|raspberrypi.fritz.box[/color]";
Wobei man natürlich statt raspberrypi.fritz.box den Namen des Hosts eintragen muss, auf dem FHEM läuft. Vorsicht: Den Patch muss man nach jedem update wiederholen!

Hintergrund:
Die Funktion BlockingCall dient dazu, Aufrufe in einen eigenen Prozess auszulagern, die potenziell lange dauern, z.B. die Abfrage einer Webseite. Um die Ergebnisse zu bekommen, erzeugt BlockingCall ein temporäres telnet Device. Um Missbrauch zu verhindern, wird dabei das Attribut "allowfrom" auf "127.0.0.1" gesetzt, also den lokalen Host.

Wenn der ausgelagerte Prozess nun fertig ist, meldet er sich über dieses telnet Device mit dem Ergebnis. Dabei überprüft das telnet Device in TcpServer Utils.pm, ob diese Verbindung überhaupt zulässig ist:
       my $hostname = gethostbyaddr($iaddr, AF_INET);
      if(!$hostname || $hostname !~ m/$af/) {
        Log3 $name, 1, "Connection refused from $caddr:$port";
        close($clientinfo[0]);
        return undef;
      }

Dabei bekommt er - zumindest bei meiner Konfiguration - den Hostname, also "raspberrypi.fritz.box" zurück und eben nicht die IP Adresse von localhost und lehnt den Aufbau der Verbindung ab.

Bitte um Hilfe
Mir ist immer noch nicht klar, ob das Problem vor dem Computer sitzt, es also irgendein Problem mit der Konfiguration gibt. So, wie der Code bei mir läuft, kann er nicht funktionieren, was ich mir aber bei einer so grundlegenden Funktion nicht vorstellen kann. Bevor ich also eine Fehlermeldung einstellen, erstmal die Anfängerfrage: Was liegt schief in meiner Konfiguration, bzw. Wo müsste ich noch hinfassen, damit sich BlockingCall anders verhält? Oder ist das ein Fall für einen Bugreport? Wenn ja, wo stelle ich den ein?
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 10:29:33
Bitte entferne erstmal den Unsinn den Du als Patch bezeichnest, als nächstes machst du bitte ein ip add auf Deinem FHEM Host und zwar mit root rechten. Die Ausgabe hier posten und dann bitte noch cat /etc/hosts und die Ausgabe hier posten.


Grüße
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 11:06:20
Zitat von: CoolTux am 08 Dezember 2019, 10:29:33
Bitte entferne erstmal den Unsinn den Du als Patch bezeichnest...

Ach, gelobt sei, was funktioniert  ;) Und danke, dass Du mir hilfst!

Hier der ip add:

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether b8:27:eb:53:d2:e4 brd ff:ff:ff:ff:ff:ff
3: wlan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether b8:27:eb:06:87:b1 brd ff:ff:ff:ff:ff:ff
    inet 192.168.178.56/24 brd 192.168.178.255 scope global wlan0
       valid_lft forever preferred_lft forever
    inet6 2a02:810d:1500:175c:ba27:ebff:fe06:87b1/64 scope global mngtmpaddr dynamic
       valid_lft 4041sec preferred_lft 1341sec
    inet6 fe80::ba27:ebff:fe06:87b1/64 scope link
       valid_lft forever preferred_lft forever
4: br0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
    link/ether fe:da:f3:90:03:e0 brd ff:ff:ff:ff:ff:ff
    inet 192.168.253.1/24 brd 192.168.253.255 scope global br0
       valid_lft forever preferred_lft forever
    inet6 fe80::a7:c0ff:fe62:b74a/64 scope link
       valid_lft forever preferred_lft forever
6: vethpivccu@if5: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master br0 state UP group default qlen 1000
    link/ether fe:da:f3:90:03:e0 brd ff:ff:ff:ff:ff:ff link-netnsid 0
    inet6 fe80::fcda:f3ff:fe90:3e0/64 scope link
       valid_lft forever preferred_lft forever


Und hier die /etc/hosts:

127.0.0.1       localhost
::1             localhost ip6-localhost ip6-loopback
ff02::1         ip6-allnodes
ff02::2         ip6-allrouters

127.0.0.1       raspberrypi
127.0.0.1       respberrypi.fritz.box 


Was spannend ist: Das telnet Device versucht die Verbindung nicht über 127.0.0.1 aufzubauen, sondern über die vom DNS Server zugewiesene IP Adresse 192.168.178.56.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 11:16:53
Ändere bitte einmal das

127.0.0.1       raspberrypi
127.0.0.1       respberrypi.fritz.box


in


192.168.178.56   respberrypi.fritz.box  respberrypi


Zu mindest wäre dann der hosts Eintrag schon mal korrekt.
Der Name ist doch noch respberrypi oder?
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 11:53:27
Hab vor vielen Jahren mal gelernt, dass man nicht spät Nachts noch an Systemfiles rumfummeln soll... Danke für den Hinweis, der "respberrypi" war natürlich Quatsch. Die /etc/hosts lautet nun

[b]pi@raspberrypi:~[/b] $ cat /etc/hosts
127.0.0.1       localhost
::1             localhost ip6-localhost ip6-loopback
ff02::1         ip6-allnodes
ff02::2         ip6-allrouters

192.168.178.56  respberrypi.fritz.box  respberrypi


Shutdown restart auf FHEM habe ich ebenfalls durchgeführt. Allerdings kommt auf {TestBlocking(3)} noch immer der Log-Eintrag

2019.12.08 11:43:40 1: Connection refused from 192.168.178.56:40380

Problem besteht also weiter...
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 12:09:18
Mach mal bitte

list TYPE=allowed
und
list TYPE=telnet


Grüße
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 14:37:02
list TYPE=allowed

Internals:
   FUUID      5dc81011-f33f-18f0-6482-75f4acb90d5da820
   NAME       allowed_WEB
   NR         14
   STATE      validFor:WEB
   TYPE       allowed
   validFor   WEB
   READINGS:
     2019-12-08 11:41:26   state           validFor:WEB
Attributes:
   basicAuth  amVuc2M6ZmhlbQ==
   room       ZZSystem
   validFor   WEB


list TYPE=telnet:

Internals:
   CFGFN     
   CONNECTS   18
   DEF        0
   FD         12
   FUUID      5decd35e-f33f-18f0-b4f1-ec54d782b5757d4a
   NAME       telnetForBlockingFn_1575801694
   NR         62
   PORT       35647
   STATE      Initialized
   TEMPORARY  1
   TYPE       telnet
   READINGS:
     2019-12-08 11:41:34   state           Initialized
Attributes:
   allowfrom  127.0.0.1
   room       hidden


11:41 war der letzte Restart
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 14:59:58
Erweitere mal beim telnet das allowedFrom auf die IP vom FHEM Server
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 15:38:10
Hm, das telnet device wird automatisch in Blocking.pm definiert (siehe Code unten) und dabei wird das allowfrom ebenfalls gesetzt. Ich hab's jetzt mal händisch über die Oberfläche gesetzt:

telnetForBlockingFn_1575812813
telnetForBlockingFn_1575815203
telnetForBlockingFn_1575815514


Was aber nicht wirklich hilft:

2019.12.08 15:26:43 3: telnetForBlockingFn_1575815203: port 46761 opened
2019.12.08 15:26:43 1: Connection refused from 192.168.178.56:55196
2019.12.08 15:26:48 1: Aborted: AbortArg


Grund ist, dass der BlockingCall einfach ein neues Device anlegt, wenn das telnet ein anderes allowfrom hat (4. Zeile im foreach-Block).

Ich könnte schon auch an der Stelle rumfummeln, wo es erzeugt wird, aber dann sind wir wieder genau bei dem Hack, der Dir eingangs nicht so wirklich gefallen hat. (Damit es funktioniert, müsste man nicht die IP Adresse, sondern den Hostname dort eintragen).

Stelle in Blocking.pm, wo das device definiert wird (Dritte Zeile von unten):
sub
BC_searchTelnet($)
{
  my ($blockingFn) = @_;

  if($BC_telnet) {
    $BC_telnetDevice = $BC_telnet;
    return;
  }

  $BC_telnetDevice = undef;
  foreach my $d (sort keys %defs) { #
    my $h = $defs{$d};
    next if(!$h->{TYPE} || $h->{TYPE} ne "telnet" || $h->{SNAME});
    next if(AttrVal($d, "SSL", undef) ||
            AttrVal($d, "allowfrom", "127.0.0.1") ne "127.0.0.1");
    next if($h->{DEF} !~ m/^\d+( global)?$/);
    next if($h->{DEF} =~ m/IPV6/);

    my %cDev = ( SNAME=>$d, TYPE=>$h->{TYPE}, NAME=>$d.time() );
    next if(Authenticate(\%cDev, undef) == 2);    # Needs password
    $BC_telnetDevice = $d;
    last;
  }

  # If not suitable telnet device found, create a temporary one
  if(!$BC_telnetDevice) {
    $BC_telnetDevice = "telnetForBlockingFn_".time();
    my $ret = CommandDefine(undef, "-temporary $BC_telnetDevice telnet 0");
    if($ret) {
      $ret = "BlockingCall ($blockingFn): ".
                "No telnet port found and cannot create one: $ret";
      Log 1, $ret;
      return undef;
    }
    $attr{$BC_telnetDevice}{room} = "hidden"; # no red ?, Forum #46640
    $attr{$BC_telnetDevice}{allowfrom} = "127.0.0.1";
  }
}


Hack, der funktioniert:
     
$attr{$BC_telnetDevice}{allowfrom} = "127.0.0.1|raspberrypi.fritz.box";
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 15:50:09
Ah, OK jetzt verstehe ich. Hatte ich auf dem Handy nicht gesehen. Aber irgendwas passt bei Dir einfach nicht.
Abhilfe schafft eventuell das definieren eines telnet Devices. Es sollte aber auch ohne gehen.
Zum testen lege aber einfach mal eines an.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 17:46:06
Hi,

Das eigene telnet Device mag er nicht (diesmal Loglevel 5):

2019.12.08 17:20:48 5: Cmd: >{TestBlocking(3)}<
2019.12.08 17:20:49 4: BlockingCall (DoSleep): created child (4078), uses telnetForBlockingFn_1575818839 to connect back
2019.12.08 17:20:49 4: WEB: /fhem&fw_id=75&room=ZZSystem&fwcsrf=csrf_180474433264716&cmd=%7BTestBlocking%283%29%7D / RL:1499 / text/html; charset=UTF-8 / Content-Encoding: gzip
/ Cache-Control: no-cache, no-store, must-revalidate

2019.12.08 17:20:49 1: Connection refused from 192.168.178.56:43686
2019.12.08 17:20:49 4: WEB_192.168.178.36_57609 GET /fhem?XHR=1&inform=type=status;filter=;since=1575822048;fmt=JSON&fw_id=75&timestamp=1575822049183; BUFLEN:0
2019.12.08 17:20:54 1: Aborted: AbortArg


Das ist unabhängig davon, ob ich das testTelnet per Default definiere, oder ihm ein allowfrom gebe, weil der BlockingCall ohnehin sein eigenes generiert.

Was ich nicht verstehe: Warum arbeitet er bei meiner Installation mit der IP Adresse des Hosts und nicht mit 127.0.0.1 als Local Host? In TcpServerUtils.pm holt er sich die Adresse von Socket - und hat da offensichtlich keinen localhost drin. 

my ($port, $iaddr) = $hash->{IPV6} ?
      sockaddr_in6($clientinfo[1]) :
      sockaddr_in($clientinfo[1]);
  my $caddr = $hash->{IPV6} ?
                inet_ntop(AF_INET6(), $iaddr) :
                inet_ntoa($iaddr);


Könnte es damit zusammen hängen, dass ich vor FHEM das pivccu installiert habe, das in einem lxc Container läuft und sich wild Netzwerkbridges aufgebaut hat?
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 18:00:46
Zitat von: Jensc am 08 Dezember 2019, 17:46:06
Hi,

Das eigene telnet Device mag er nicht (diesmal Loglevel 5):

2019.12.08 17:20:48 5: Cmd: >{TestBlocking(3)}<
2019.12.08 17:20:49 4: BlockingCall (DoSleep): created child (4078), uses telnetForBlockingFn_1575818839 to connect back
2019.12.08 17:20:49 4: WEB: /fhem&fw_id=75&room=ZZSystem&fwcsrf=csrf_180474433264716&cmd=%7BTestBlocking%283%29%7D / RL:1499 / text/html; charset=UTF-8 / Content-Encoding: gzip
/ Cache-Control: no-cache, no-store, must-revalidate

2019.12.08 17:20:49 1: Connection refused from 192.168.178.56:43686
2019.12.08 17:20:49 4: WEB_192.168.178.36_57609 GET /fhem?XHR=1&inform=type=status;filter=;since=1575822048;fmt=JSON&fw_id=75&timestamp=1575822049183; BUFLEN:0
2019.12.08 17:20:54 1: Aborted: AbortArg


Das ist unabhängig davon, ob ich das testTelnet per Default definiere, oder ihm ein allowfrom gebe, weil der BlockingCall ohnehin sein eigenes generiert.

Was ich nicht verstehe: Warum arbeitet er bei meiner Installation mit der IP Adresse des Hosts und nicht mit 127.0.0.1 als Local Host? In TcpServerUtils.pm holt er sich die Adresse von Socket - und hat da offensichtlich keinen localhost drin. 

my ($port, $iaddr) = $hash->{IPV6} ?
      sockaddr_in6($clientinfo[1]) :
      sockaddr_in($clientinfo[1]);
  my $caddr = $hash->{IPV6} ?
                inet_ntop(AF_INET6(), $iaddr) :
                inet_ntoa($iaddr);


Könnte es damit zusammen hängen, dass ich vor FHEM das pivccu installiert habe, das in einem lxc Container läuft und sich wild Netzwerkbridges aufgebaut hat?

Mach mal bitte ein list vom definierten telnet Device
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 18:07:10
defmod telnetPort telnet 7072 global
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 18:42:29
Zitat von: CoolTux am 08 Dezember 2019, 18:07:10
defmod telnetPort telnet 7072 global

Yeap, das hat geholfen (aber erst, nachdem ich das alte telnet Device gelöscht hatte)!
2019.12.08 18:38:50 5: Cmd: >{TestBlocking(3)}<
2019.12.08 18:38:50 4: BlockingCall (DoSleep): created child (6257), uses telnetPort to connect back
2019.12.08 18:38:50 4: WEB: /fhem&fw_id=139&fwcsrf=csrf_180474433264716&cmd=%7BTestBlocking%283%29%7D / RL:1783 / text/html; charset=UTF-8 / Content-Encoding: gzip
/ Cache-Control: no-cache, no-store, must-revalidate

2019.12.08 18:38:50 4: Connection accepted from telnetPort_192.168.178.56_52196
2019.12.08 18:38:50 5: Cmd: >{BlockingRegisterTelnet($cl,22)}<
2019.12.08 18:38:50 4: WEB_192.168.178.63_55564 GET /fhem?XHR=1&inform=type=status;filter=;since=1575826729;fmt=JSON&fw_id=139&timestamp=1575826730567; BUFLEN:0
2019.12.08 18:38:53 5: Cmd: >{BlockingStart('22')}<
2019.12.08 18:38:53 5: Cmd: >{SleepDone('I\'m done')}<
2019.12.08 18:38:53 1: SleepDone: I'm done


Frage: Habe ich jetzt einen offenen telnet Port auf dem Raspi, über den jeder rein kann, der im lokalen Netz ist? Das würde ich dann noch nicht als echte Lösung ansehen... Oder wie kann ich den zu machen?

Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 08 Dezember 2019, 18:47:49
Ok was mich die ganze Zeit Stutzig macht ist wieso das Telnet Device die ganze Zeit existent war. Eigentlich hätte es sich von alleine wieder löschen müssen.
Und ja aktuell hast Du ein offenes Telnet. Du kannst es aber mit einem allowed Device absichern. Schau dazu bitte in die Commandref.

Interessant für mich wäre das Verhalten ohne jegliches telnet Device. Also das neue auch wieder entfernen und schauen ob noch ein anderes da ist. Wenn ja löschen. So das keines mehr da ist. Danach dann mal testen.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 08 Dezember 2019, 23:07:34
Wenn alle telnet Devices gelöscht wurden, zeigt er wieder das alte Verhalten: Anlegen eines temporären Devices, Ablehnen der Verbindung und das Device bleibt dann stehen.

2019.12.08 22:58:41 5: Cmd: >{TestBlocking(3)}<
2019.12.08 22:58:41 3: telnetForBlockingFn_1575842321: port 36549 opened
2019.12.08 22:58:41 4: BlockingCall (DoSleep): created child (11226), uses telnetForBlockingFn_1575842321 to connect back
2019.12.08 22:58:41 4: WEB: /fhem&fw_id=175&fwcsrf=csrf_180474433264716&cmd=%7BTestBlocking%283%29%7D / RL:1768 / text/html; charset=UTF-8 / Content-Encoding: gzip
/ Cache-Control: no-cache, no-store, must-revalidate

2019.12.08 22:58:41 1: Connection refused from 192.168.178.56:35534
2019.12.08 22:58:41 4: WEB_192.168.178.36_57816 GET /fhem?XHR=1&inform=type=status;filter=;since=1575842320;fmt=JSON&fw_id=175&timestamp=1575842321274; BUFLEN:0
2019.12.08 22:58:46 1: Aborted: AbortArg


Und auf list TYPE=telnet:
Internals:
   CFGFN     
   CONNECTS   3
   DEF        0
   FD         17
   FUUID      5ded7211-f33f-18f0-7d9d-87dc943887c6e30a
   NAME       telnetForBlockingFn_1575842321
   NR         180
   PORT       36549
   STATE      Initialized
   TEMPORARY  1
   TYPE       telnet
   READINGS:
     2019-12-08 22:58:41   state           Initialized
Attributes:
   allowfrom  127.0.0.1
   room       hidden

Ich werde die nächsten Tage wenig Zeit haben, es kann also ein paar Tage dauern, bis ich wieder antworte. Trotzdem wäre ich auch daran interessiert, herauszufinden, was das eigentlich zugrundeliegende Problem ist. Auch wenn das globale telnet Device dazu führt, dass das Problem nicht mehr auftritt, gehört es ja wohl nicht zur Standard-Installation, oder? Bis dahin würde ich es auch noch nicht als "gelöst" kennzeichnen.

Das allowed Device werde ich mir noch zu Gemüte führen. Erstmal Danke bis hierhin.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 09 Dezember 2019, 08:09:57
Ich habe nun mal eine Testinstanz installiert und bin zu folgender Erkenntnis gelangt.
Sofern man kein Telnetdevice angelegt hat wird beim aller ersten BlockingCall eines angelegt. Es wird als temporär deklariert und bleibt bis zum neustart erhalten.
Bei mir wird bei einem BlockingCall das loopback device verwendet, also 127.0.0.1.

Mach mal bei Dir bitte ein
hostname
und
hostname -f

Beide Ausgaben hier posten


Grüße
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 09 Dezember 2019, 08:21:36
Du kannst auch mal schauen wie localhost aufgelöst wird.

nslookup localhost
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 09 Dezember 2019, 22:05:28
Sieht alles eher unauffällig aus:
pi@raspberrypi:~ $ hostname
raspberrypi
pi@raspberrypi:~ $ hostname -f
raspberrypi.fritz.box
pi@raspberrypi:~ $ nslookup localhost
Server:         192.168.178.1
Address:        192.168.178.1#53

Name:   localhost
Address: 127.0.0.1


Irgendwo wird bei mir aus dem localhost der "raspberrypi" und entsprechend aus der loopback IP die echte IP. Die Stelle habe ich aber noch nicht gefunden.

Nachtrag: Den telnet mit einem allowed Device abzusichern funktioniert übrigens nicht: In dem Moment, wo ich ein Passwort setze, macht der BlockingCall wieder sein eigenes telnet Device, das dann scheitert. Wenn man das allowed Device und das von BlockingCall angelegte telnet Device löscht, geht's wieder
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 10 Dezember 2019, 04:30:48
Sieht in der Tat unauffällig aus.
Bin mir ziemlich sicher das es dennoch vom OS kommt.

Du sollst ja auch kein Passwort setzen sondern das Attribut allowed_from auf 127.0.0.1 und Deine eigene IP


Grüße
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 10 Dezember 2019, 22:18:41
Ja, Deinen Verdacht mit dem OS teile ich auch - leider sind mir die Ideen ausgegangen, wo ich noch suchen kann.

Wg telnet abdichten: Da hatte ich offensichtlich Deinen Post falsch verstanden. Allerdings hilft allowedfrom am telnet Device auch nicht so richtig: Es führt wieder dazu, dass sich Blocking ein eigenes telnet Device schafft Alles andere hätte mich auch ernsthaft erstaunt, wenn man sich die Stelle anschaut, wo das telnet Device im BlockingCall gesucht bzw. erzeugt wird (Ausschnitt aus Blocking.pm, ein wenig gekürzt):
sub
BC_searchTelnet($)
{
   ...

  $BC_telnetDevice = undef;
  foreach my $d (sort keys %defs) { #
    my $h = $defs{$d};
    next if(!$h->{TYPE} || $h->{TYPE} ne "telnet" || $h->{SNAME});
    next if(AttrVal($d, "SSL", undef) ||
            AttrVal($d, "allowfrom", "127.0.0.1") ne "127.0.0.1");
    next if($h->{DEF} !~ m/^\d+( global)?$/);
    next if($h->{DEF} =~ m/IPV6/);

    my %cDev = ( SNAME=>$d, TYPE=>$h->{TYPE}, NAME=>$d.time() );
    next if(Authenticate(\%cDev, undef) == 2);    # Needs password
    $BC_telnetDevice = $d;
    last;
  }

  # If not suitable telnet device found, create a temporary one
 
  ...
}


Wenn mich meine rudimentären Perl-Kenntnisse nicht täuschen, wird da alles ignoriert, was nicht genau "127.0.0.1" als allowfrom hat, ein Passwort hat, nicht global ist, oder mit IPV6 arbeitet.

Ich überlege mittlerweile, ob ich nicht einen Änderungsantrag stelle, aus dem "ne" in "AttrVal($d, "allowfrom", "127.0.0.1") ne "127.0.0.1");" ein matches zu machen. Dann sollte genau das funktionieren, was Du vorgeschlagen hast. Wo müsste man sowas reinstellen?
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 11 Dezember 2019, 08:05:25
Den Vorschlag kannst Du natürlich machen. Rudi wird Dich dann nach den Anwendungsgrund für diese Änderung fragen. Und ich denke wenn Du sagst weil mein System nicht richtig arbeitet wird er bestimmt absagen. Ist meine Vermutung!!!

Ich würde da wirklich lieber versuchen das System gerade zu richten oder FHEM zu sichern und das System neu auf zu setzen.

Du kannst auch mal versuchen einen neuen Hostname zu vergeben und entsprechend die /etc/hosts an zu passen und wenn noch nicht geschehen eine feste IP zu vergeben.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 16 Dezember 2019, 22:54:51
Nachdem ich im OS nicht wirklich fündig geworden bin, habe ich mich dafür entschieden, /opt/fhem/FHEM/Blocking.pm in Zeile 51 zu patchen, nur etwas sauberer, als vorher. In dem folgenden Abschnitt

foreach my $d (sort keys %defs) { #
    my $h = $defs{$d};
    next if(!$h->{TYPE} || $h->{TYPE} ne "telnet" || $h->{SNAME});
    next if(AttrVal($d, "SSL", undef) ||
            AttrVal($d, "allowfrom", "127.0.0.1") ne "127.0.0.1");
    next if($h->{DEF} !~ m/^\d+( global)?$/);
    next if($h->{DEF} =~ m/IPV6/);

    my %cDev = ( SNAME=>$d, TYPE=>$h->{TYPE}, NAME=>$d.time() );
    next if(Authenticate(\%cDev, undef) == 2);    # Needs password
    $BC_telnetDevice = $d;
    last;
  }


wird statt
AttrVal($d, "allowfrom", "127.0.0.1") ne "127.0.0.1");

die Zeile
AttrVal($d, "allowfrom", "127.0.0.1") !~ m/127.0.0.1/);
eingesetzt. Das erlaubt es, ein telnet Device mit

define telnetPort telnet 7072
attr telnetPort allowfrom 127.0.0.1|<hostname>

zu konfigurieren, wodurch man nicht mehr auf einen offenen telnet Port angewiesen ist. <hostname> muss natürlich durch den Namen des hosts ersetzt werden, auf dem fhem läuft, also in meinem Beispiel
attr telnetPort allowfrom 127.0.0.1|raspberrypi
Einziger Nachteil: Beim update des Systems wird einem die alte Version wieder eingespielt, d.h. man kann sich die Mühe entweder nach jedem Update machen, oder aber ein kleines sed Skript bauen, das einem die Arbeit erledigt. Und das ganze ist natürlich völlig ohne Gewähr

Wenn Dir die Lösung geholfen hat, hinterlasse hier bitte einen Kommentar. Wenn zehn Kommentare zusammen gekommen sind, stelle ich den Patch als Änderungsantrag.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: CoolTux am 16 Dezember 2019, 23:06:45
Ein sed Skript ist Unsinn. MAche doch einfach direkt ein Patch File und spiele das dann halt immer wieder ein nach einem Update.
Titel: Antw:"Connection refused" bei Blocking Call [was: DWD_OpenData läuft auf Fehler...]
Beitrag von: Jensc am 16 Dezember 2019, 23:14:41
Zitat von: CoolTux am 16 Dezember 2019, 23:06:45
Ein sed Skript ist Unsinn. MAche doch einfach direkt ein Patch File und spiele das dann halt immer wieder ein nach einem Update.
Das hat halt den Nachteil, dass man sich auch evtl. Änderungen an Blocking.pm überschreibt. Aber ich gebe Dir Recht: Ob sed, awk, perl oder Patch File kann jeder nach Belieben gestalten. Hat wohl eher was mit Geschmack und Vorlieben zu tun.

Danke Dir noch mal für Deine Hilfe!