UPnP - Simple Service Discovery Protocol (SSDP) als Basismodul

Begonnen von klaus.schauer, 23 September 2020, 20:19:55

Vorheriges Thema - Nächstes Thema

KölnSolar

#75
Hi Klaus,
das hab ich kaum anders erwartet.
Mittlerweile bin ich mir sicher, dass der Unterschied in unseren System viel "tiefer" liegt. Nämlich in den Perl-Paketen wie HTTP, SOAP.... Die lassen sich dann weder debuggen, noch werfen sie Logausgaben aus. Ich hab mir damals eigene Print-Ausgaben eingebaut, um "näher" an die freeze-Verursacher zu kommen. Es kann auch sein, dass ich dort etwas modifiziert habe. Sehe dort aber kein Eingreifen meinerseits. In meinen Aufzeichnungen habe ich nur gefunden, dass auch ich damals irgendwelche freeze-Problem hatte, die in einem System vorhanden waren, im anderen nicht.
Ich kann jetzt nur hingehen und erst einmal mein System(Rpi/buster) komplett auf einen "frischen" Auslieferungszustand bzgl. Perl(und perlupnp) zurücksetzen.

Was mich bei Deinen freezes wundert, ist das völlig undefinierte Zeitverhalten. Die freezes, die ich bisher im Zusammenhang mit perlupnp kenne, basieren immer auf irgendwelchen HTTP-Zugriffsproblemen, die wenigstens über "timeouts" regelmäßig waren. Z.B. immer 20s. Außerdem sind entsprechende Probleme immer in perlupnp mit carp/croak "abgefangen". Durch ein eval meinerseits lässt sich dann der Absturz verhindern und die Meldung loggen.

Mir scheint, dass Dein Problem ganz woanders liegt(sowas wie ne firewall ?). Du müsstest also mal ein bißchen mehr Statistik über das freeze-Verhalten machen, damit wir überhaupt mal eine Idee entwickeln können, wo es klemmt. Vielleicht auch mal den Datentraffic aufzeichnen(Wireshark/tcpdump) und analysieren.

Welche OS-Version und Releasestand hast Du ?

Grüße Markus

Edit: Gerade ist mir noch in den Sinn gekommen, dass der UPNPController seine Server ja auch nicht anders aufbaut. Im Gegensatz zu UPNPDevice ist es aber auf einigen Systemen problemlos. Läuft der UPNPController(mit freezemon) auf Deinem Testsystem problemlos ? Werden DLNA-devices automatisch angelegt, was dann bedeuten würde, dass auch der subscription process mit seinem Server problemlos läuft ?
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

klaus.schauer

#76
Auf den Servern läuft Raspberry Pi OS Buster in der jeweils aktuellen Version, Raspi 1B mit 32 bit oder Raspi 4B mit 64 bit. Folgende Pakete sind installiert:


perl libdevice-serialport-perl libio-socket-ssl-perl libwww-perl libdatetime-format-strptime-perl
liblist-moreutils-perl libxml-simple-perl libtext-csv-perl libarchive-extract-perl libcrypt-rijndael-perl
libcrypt-random-source-perl libstring-random-perl libdata-random-perl libyaml-perl sendemail libjson-perl
sqlite3 libdbd-sqlite3-perl libtext-diff-perl libdbi-perl libcgi-pm-perl libio-socket-multicast-perl libdigest-crc-perl
unattended-upgrades wiringpi libmodule-pluggable-perl git ser2net
libwww-perl libsoap-lite-perl libxml-parser-lite-perl


Der UPNPController auf dem Raspi 1B scheint problemlos zu laufen. Die UPnP-Devices im Netz werden alle gelistet.

Es gibt zwar viele freezemon-Meldungen, siehe Anlage. Das scheint mir aber auf das laufenden PIFACE-Modul zurückzuführen zu sein. Das startet im Sekundentakt mehrere Aufrufe auf Shell-Ebene über wiringpi zur Abfrage der GPIOs. Die durchschnittliche CPU-Last des Servers liegt bei ca. 20 % bis 25 %. Das Modul freezemon scheint auch zusätzlichen einen Anteil daran zu haben. Ein Raspi 1B ist nicht der schnellste.

Blockaden im Datentransfer sehe ich nicht. Die Geräte hängen alle an internen Switchen ohne Firewallfunktionen oder Portsperren.

KölnSolar

[Freezemon] freezemon: possible freeze starting at 01:55:01, delay is 1.235 possibly caused by: tmr-PIFACE_GetUpdate(N/A) tmr-PIFACE_Watchdog(N/A)
2022.01.14 01:55:00.565 5: UPNPController: incoming message; will be processed by perlupnp handleOnce
2022.01.14 01:55:00.573 5: UPNPController: UPNPSocket-UPNP_Controller-1900, received ssdp event: was checked by discoverCallback for removed or added devices against pending search requests
2022.01.14 01:55:01.553 5: UPNPController: incoming message; will be processed by perlupnp handleOnce
2022.01.14 01:55:01.554 5: UPNPController: UPNPSocket-UPNP_Controller-1900, received ssdp event: was checked by discoverCallback for removed or added devices against pending search requests
2022.01.14 01:55:02.236 5: [Freezemon] freezemon: ----------- Starting Freeze handling at 2022.01.14 01:55:02.235 ---------------------
[Freezemon] freezemon: possible freeze starting at 01:55:01, delay is 1.235 possibly caused by: tmr-PIFACE_GetUpdate(N/A) tmr-PIFACE_Watchdog(N/A)
Ich glaube fast, dass Du richtig liegst wegen der Einschätzung zu piface. Ich weiß leider auch nicht, wie freezemon auf die Idee kommt , dass der freeze von piface sein könnte. Aber wenn man auf die Log-Zeilen guckt, sieht man immer wieder ein ähnliches Muster: es kommt ein ssdp-event rein, wird blitzschnell verarbeitet und mit der "was checked" Meldung wird das Modul beendet. Danach tritt dann der freeze auf. Im obigen Log-Extrakt gut zu erkennen, dass nach Beendigung des Moduls 1s später erst die nächste message zur Verarbeitung startet, ohne dass ein FHEM-Logging dazwischen liegt.
Nur für meine Neugierde: Weißt Du, ob diese piface-Zugriffe per BlockingCall laufen ?

ZitatDie UPnP-Devices im Netz werden alle gelistet.
Und da sind auch devices mit DLNA dabei, die per autocreate angelegt und deren services subscribed wurden ?
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

KölnSolar

Seeeehr mühsam bin ich weiter. Ich denke es ist ein LAN/WLAN Problem. Ersetze mal die UPNPDevice_setupDevice mitsub UPNPDevice_setupDevice {
  my ($hash) = @_;
  my $name = $hash->{NAME};
  my $error;
  my $file = AttrVal($name,"file","/opt/fhem/description.xml"); #SEMPdevice.xml
  my $path = AttrVal($name,"path","/opt/fhem/");
  my $port = AttrVal($name,"port","4004");

  if (open(my $handle,"<",$file)) {
     close $handle;
  do {
$hash->{helper}{device} = $hash->{helper}{dm}->registerDevice(DevicePort => $port,
DescriptionFile => $file,   
DescriptionURI => $file,
ResourceDirectory => $path);
if($@) {
   $hash->{helper}{device} = undef;
   $error = "registration failed with error $@";
   Log3 $hash, 2, "UPNPDevice: device $name. $error";
   readingsSingleUpdate($hash,"state",$error,1);
   return $error;
}
else { 
   Log3 $hash, 3, "UPNPDevice: device $name returned handler-socket ".$hash->{helper}{device}{_handler}->socket." listening on port ".$hash->{helper}{device}->{_handler}->socket->sockport;
   Log3 $hash, 5, "UPNPDevice: device $name details: descriptionURI: ".$hash->{helper}{device}{_handler}->{_descriptionURI}.", DeviceDescription: ".$hash->{helper}{device}{_handler}->{_description}.", ResourceDirectory: ".$hash->{helper}{device}{_handler}->{_resourceDir}.", Server: ".$hash->{helper}{device}{_handler}->{_server};
   $hash->{helper}{device}{_handler}->socket->timeout(1); #avoid freezes longer than 1s
   UPNPDevice_addSocketDeviceToMainloop($hash);
}
   } # while($error);
  }
  else {
     Log3 $hash, 2, "UPNPDevice: device  $name failed to open $file $!";
  } 

  readingsSingleUpdate($hash,"state","registered",1);

  return undef;
}
was den freeze auf 1s begrenzen sollte.

Der
2022.01.05 12:22:37 3: UPNPDevice: handleOnce failed, Can't call method "uri" on an undefined value at FHEM/lib/UPnP/DeviceManager.pm line 782.
steht im Zusammenhang. Ist im FHEM/lib/UPnP/DeviceManager.pm nicht sauber programmiert, aber nicht so wichtig(Halten wir mal im Hinterkopf ggfs. das perlupnp zu modifizieren.)
Grüße Markus
PS: Das Ganze hatte aber wenigstens den positiven Lerneffekt, dass ich auf eine andere Modifikation in perlupnp verzichten kann und denselben Effekt im FHEM-Modul erreiche. 8)
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

klaus.schauer

Danke für die weitere Fehleranalyse.
Zitat
Ich denke es ist ein LAN/WLAN Problem.
Grundsätzlich oder u. U. bei meiner Netz- / oder Serverkonfiguration?

Nach dem Tausch des Routine UPNPDevice_setupDevice startet Fhem ständig neu. Die dort aufgerufene Routine UPNPDevice_addSocketDeviceToMainloop kann in UPNPDevice nicht gefunden werden. Ist diese identisch zur bisherigen Routine UPNPDevice_addSocketsToMainloop?

KölnSolar

ZitatGrundsätzlich oder u. U. bei meiner Netz- / oder Serverkonfiguration?
Ich denke grundsätzlich. Alles sehr ominös(für mich). Die freezedauer ist performance-abhängig, weshalb bei Deinem Rpi1 sehr lange freezes auftreten.
ZitatDie dort aufgerufene Routine UPNPDevice_addSocketDeviceToMainloop kann in UPNPDevice nicht gefunden werden
Sorry. Bei mir ist viel mehr geändert. Lass diese Zeile einfach weg.
Ich brauch noch etwas bis zur nächsten Version.
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

klaus.schauer

Bei den ersten Tests kann ich keine Blockaden mehr feststellen. freezemon liefert auch keine Meldungen mehr. Es kommen aber weiterhin Meldungen wie:

2022.01.23 12:31:25 3: UPNPDevice: handleOnce failed, Can't call method "uri" on an undefined value at FHEM/lib/UPnP/DeviceManager.pm line 782.


Auch kann man das Attribut "file" nicht per Kommando ändern. Die WEB-Seite reagiert danach für einige Sekunden nicht mehr. Die Änderungen werden nicht übernommen. freezemon liefert aber keine Meldung. Falls man statt dessen das fhem.cfg manuell editiert, werden die Änderungen nach einem Restart übernommen. Wenn ich mich recht erinnere, ist das aber ein bereits bekannter Fehler.

KölnSolar

ZitatBei den ersten Tests kann ich keine Blockaden mehr feststellen
sehr schön
Zitat2022.01.23 12:31:25 3: UPNPDevice: handleOnce failed, Can't call method "uri" on an undefined value at FHEM/lib/UPnP/DeviceManager.pm line 782.
Schrieb ich ja.Kannst Du ignorieren.
ZitatAuch kann man das Attribut "file" nicht per Kommando ändern
Gemach. daran arbeite ich aktuell.
Mach Du mal Deine SEMP-Konfiguration, dass wir feststellen, was das Modul noch können muss.
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

KölnSolar

Neue Version im Entwicklungsthread veröffentlicht. Fehlerbehebungen, keine neuen Funktionalitäten.

Grüße Markus
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

klaus.schauer

Danke für die Überarbeitungen. Bei der Ausgabe des XML-Datei treten jetzt manchmal Blockaden auf. In diesen Fällen wird eine Abfrage wie

http://192.168.6.46:4004/opt/fhem/description.xml

erst nach Ende der Blockade beantwortet. Vorher meldet der Browser, die Seite sei nicht erreichbar. Im Fhem log kommt die Meldung:

2022.02.06 09:27:39 3: UPNPDevice: UPNPSocket-UPNPSEMP-4004, message from 192.168.6.138:51260: handleOnce failed, Can't call method "uri" on an undefined value at FHEM/lib/UPnP/DeviceManager.pm line 782.

2022.02.06 09:27:42 1: PERL WARNING: Use of uninitialized value $client_port in concatenation (.) or string at ./FHEM/98_UPNPDevice.pm line 188.
2022.02.06 09:27:42 3: UPNPDevice: UPNPSocket-UPNPSEMP-4004, message from :: handleOnce failed, accept: timeout
2022.02.06 09:27:42 1: [Freezemon] freezemon: possible freeze starting at 09:27:41, delay is 1.407 possibly caused by: tmr-CODE(0x55b7ded338)(GetUpdate) tmr-CODE(0x55b7d8be28)(ProcessRequestQueue)

freezemon liefert:

2022-02-06_09:27:42 freezemon s:09:27:41 e:09:27:42 f:1.407 d:tmr-CODE(0x55b7ded338)(GetUpdate) tmr-CODE(0x55b7d8be28)(ProcessRequestQueue)
2022-02-06_09:27:42 freezemon freezeTime: 1.407
2022-02-06_09:27:42 freezemon fcDay: 1
2022-02-06_09:27:42 freezemon ftDay: 1.407
2022-02-06_09:27:42 freezemon freezeDevice: tmr-CODE(0x55b7ded338)(GetUpdate) tmr-CODE(0x55b7d8be28)(ProcessRequestQueue)

Die Blockaden dauern - soweit ich das sehen kann - unter zwei Sekunden.

Bei den Anfragen, die unmittelbar ohne Blockaden beantwortet werden, werden keine log-Meldungen ausgegeben. Bisher war ja auch in diesen Fällen Meldungen wie

... Can't call method "uri" on an undefined value ...

zu sehen.


KölnSolar

Hi Klaus,
ja, das ist die Modifikation, die ich vor ein paar Posts beschrieben hatte. Ausschließen lässt sich der freeze nicht. Nur reduzieren.
ZitatMach Du mal Deine SEMP-Konfiguration, dass wir feststellen, was das Modul noch können muss.
Und dann kann man sich die Mühe machen das Ganze non-blocking zu realisieren(womit es immer noch eine unschöne Response time gäbe aber FHEM nicht mehr behindert wird).
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

klaus.schauer

Gut dann als nächsten Schritt ein Vorschlag zur Umstellung auf ein zweistufige Modulkommunikation.


  • Verlagerung der Steuerung im UPNPDevice-Modul (set Kommandos) und Attribute file, path in die nachgelagerten Module z. B. SEMP
  • Kommandos an UPNPDevice über IOWrite >> Returns über Dispatch an z. B. SEMP (Parameter im JSON-Format):
       -  set registerDevice
          - wird aus X_Define gesendet
          - IOWrite-Parameter: 'registerDevice', <DevicePort>, <descriptionURI>, <LeaseTime>, <Description>, <DescriptionFile>, <ResourceDirectory>
          - Return per Dispatch: 'registerDevice', <object-Kennzeichen>|<error>
       - set start
          - wird aus X_Define oder set-Kommando nach erfolgreichem registerDevice gesendet
          - IOWrite-Parameter: 'start', <object-Kennzeichen>
          - Return per Dispatch: 'start', <object-Kennzeichen>|<error>
       - set stop
          - wird aus X_Undef oder set-Kommando nach erfolgreichem start gesendet
          - IOWrite-Parameter: 'stop', <object-Kennzeichen>
          - Return per Dispatch: 'stop', <object-Kennzeichen>|<error>
       - set advertise
          - wird aus set-Kommando nach erfolgreichem start gesendet
          - IOWrite-Parameter: 'advertise', <object-Kennzeichen>
          - Return per Dispatch:  'advertise', <object-Kennzeichen>|<error>
  • sonstige Statusmeldungen von UPNPDevice über Dispatch an SEMP und Co.
    - ?
Auch könnte man ggf. den Modul-Start von UPNPDevice noch automatisieren, indem man in den nachgelagerten Modulen prüft, ob das passende IODev (UPNPDevice) definiert ist.

Falls das grundsätzlich so machbar wäre, müssten wir festlegen, wie wir die notwendigen Anpassungen in UPNPDevice organisieren. Um das SEMP-Modul kümmere ich mich natürlich.

KölnSolar

Hallo Klaus,
kann man ja alles so machen. Bevor ich weiteren Aufwand investiere, möchte ich aber erst einmal Deine konkrete Anwendung/Konzept zu SEMP sehen.
Zitat
Mach Du mal Deine SEMP-Konfiguration, dass wir feststellen, was das Modul noch können muss.
Ich entwickle daran ja nicht, weil ich Spaß an Perl habe, sondern weil ich notwendige/hilfreiche Funktionalität für FHEM bereitstellen möchte. Das erfüllt die jetzige Version ja jetzt bereits. Wenn Automatismen fehlen, lässt sich das zumindest halbmanuell durchspielen.
Den Umgang mit dem 2-stufigen Modulkonzept kriege ich problemlos hin, da ich das über UPNP-/DLNAController ganz gut gelernt habe.  ;)
Grüße Markus
RPi3/2 buster/stretch-SamsungAV_E/N-RFXTRX-IT-RSL-NC5462-Oregon-CUL433-GT-TMBBQ-01e-CUL868-FS20-EMGZ-1W(GPIO)-DS18B20-CO2-USBRS232-USBRS422-Betty_Boop-EchoDot-OBIS(Easymeter-Q3/EMH-KW8)-PCA301(S'duino)-Deebot(mqtt2)-zigbee2mqtt

justme1968

nicht um hier etwas weg zu nehmen, sondern weil ich denke upnp/ssdp und mdns/dns-sd zusammen gehören: ich habe hier gerade eine erste version einer mdns/dns-sd implementierung für fhem gepostet: https://forum.fhem.de/index.php/topic,126262.0.html .

auch wenn ich gerade nicht besonders schnell mit dem thema und dem netdiscover modul bin gibt es einige berührungspunkte und es wäre schön wenn zumindest die dinge wie das automatische sammeln der daten im hintergrund und diese dann für andere module bereitstellen nicht komplett auseinander laufen.

ps: ihr scheint zumindest zum teil vorhandene perl upnp libs zu verwenden, mein ziel ist bisher vor allem so weit es geht ohne externe module auszukommen. ich hoffe auch das beisst sich nicht.
hue, tradfri, alexa-fhem, homebridge-fhem, LightScene, readingsGroup, ...

https://github.com/sponsors/justme-1968

klaus.schauer

#89
Nun kann ich die Funktionalität des Moduls UPNPDevice zusammen mit dem SEMP testen. Der Prototyp des SEMP Web-Service Dienstes in Fhem ist fertig, sodass alle Funktion für den Test der Kommunikation mit dem Home Manager vorhanden sind. Leider reagiert der Home Manager nicht auf die NOTIFY-Telegramme des UPNPDevice Modules. Folgendes ist mir aufgefallen:

1. Die UPnP Device Beschreibung (description.xml) wird von diesem nicht auf Fhem abgerufen. Die ssdp-Telegramme sehen auf den ersten Blick gut aus. Ungewöhnlich sind die Steuerzeichen an den Zeilenenden - \n statt \r\n -. Vielleicht hat der Home Manager damit ein Problem. Die mitgeschnittenen Telegramme sind in der angehängten Textdatei zu finden.

2. Die NOTIFY  ssdp:byebye-Telegramme werden beim FHEM shutdown nicht gesendet. Mit dem Kommando "stop" klappt es.

3. Der Home Manager sendet regelmäßig M-Search Requests. Das Modul UPNPDevice antwortet darauf aber nicht. Ein Beispiel für ein passendes M-Search Response ist ebenfalls in der Textdatei enthalten.

4. Im SEMP Kontext wird erwartet, dass die NOTIFY ssdp:alive Telegramme z. B. bei CACHE-CONTROL: max-age = 1800 in Abständen von ca. 900 s gesendet werden. Das Modul UPNPDevice sendet derzeit alle 1800 s. Ob das eine SEMP-Besonderheit ist oder so im ssdp-Standard vorgesehen ist, kann ich augenblicklich nicht beurteilen.

Um beim SEMP-Modul wirklich weiterzukommen, benötige ich erst einmal eine funktionsfähige Kommunikation mit dem Home Manager. Aus den Unterlagen ist für mich nicht eindeutig zu erkennen, wie das SEMP-Gateway in Fhem zur Steuerung mehrerer Devices gestaltet werden muss. Das sollte sich aber klären, sobald die Kommunikation mit einer Testkonfiguration klappt.

In der Datei description.xml gab es noch einen Fehler. Deshalb sende ich diese nochmals.