Komischen Fehler mit Client Socket

JPaeper · 6. Oktober 2017 um 14:40

Hallo Leute,

mir passieren ja manchmal so komische Dinge…
Ich benutzte in meinem Modul einen „eigenen“ Client Socket zur Kommunikation mit PIGPIO.
Das funktioniert bisher auch sehr gut, jetzt aber passiert folgendes:

nach ca. 12165 Anfragen (schwankt so zwischen 12162 und 12167)
zeitlich liegt das bei 200 Minuten ~ 3 Stunden und 20 Minuten
nach ca 12165 x 500 Bytes ~ 6MB übertragenden Daten
bekomme ich den Fehler 11 (Fehler beim Empfangen 11 Die Ressource ist zur Zeit nicht verfügbar) zurück.
Das ist diverse Mal reproduzierbar…

Der Code wo der Fehler auftritt:

else {
				if(socket_recv ($this->Socket, $buf, $ResponseLen, MSG_DONTWAIT ) === FALSE) {
					$errorcode = socket_last_error();
					$errormsg = socket_strerror($errorcode);
					IPS_LogMessage("IPS2GPIO Socket", "Fehler beim Empfangen ".$errorcode." ".$errormsg);
					$this->SendDebug("CommandClientSocket", "Fehler beim Empfangen ".$errorcode." ".$errormsg, 0);
					return;
				}
			}

Da ich vor dem Lesen nicht genau weiß, wie viele Bytes dort im (PIGPIO)-Buffer liegen, setze ich die $ResponseLen auf 8192 Bytes, aber in der Regel sind es so um die 500 Bytes.
Diese Funktion die ich dort bei PIGPIO aufrufe funktioniert von anderen Applicationen aus offenbar ohne dieses Problem.

Jemand irgendeine Idee, wo da irgendetwas schief gehen könnte? In PHP? In IPS?
Sollte ich die $ResponseLen mit einem anderen Wert setzen?

Joachim

JPaeper · 7. Oktober 2017 um 16:41

…könnten die eingestellten Optionen des Sockets dieses Problem hervorrufen:

$this->Socket = socket_create(AF_INET, SOCK_STREAM, 0)

socket_set_option($this->Socket, SOL_SOCKET, SO_RCVTIMEO, array("sec"=>0, "usec"=>300000))

Nach ca. 12000 + irgendetwas immer wieder Fehler 11…

Joachim

Nall-chan · 7. Oktober 2017 um 17:33

Wie sollen so viele Aufrufe passieren, wenn der Socket doch jedesmal zerstört wird, wenn der Befehl vom Modul durchgelaufen ist. Ist ja nicht persistent.

Oder schließt du den Socket nicht am Ende, so dass irgendwann alle Ressourcen aufgebraucht sind?
Michael

JPaeper · 7. Oktober 2017 um 17:39

…der Socket wird erst „zerstört“, wenn die Module.php wirklich verlassen wird. Da hier jede Sekunde eine Menge Daten ankommen und verarbeitet werden wollen, bezweifle ich das…

Joachim

Nall-chan · 7. Oktober 2017 um 17:46

Wenn jede Sekunde neue Daten ankommen, dann erzeugt IPS jedesmal eine neue PHP-Instanz aus deinem Modul.
Jetzt ist die Preisfrage wann du dann selbst einen Socket im Modul erzeugst
Weil sonst kann es wirklich sein das entweder beim PIGPIO oder auf deinem Host alle Ressourcen belegt sind.

Eher alles Quark, und du hast einfach keine Daten zum Lesen beim recv

Hier:

Michael

JPaeper · 7. Oktober 2017 um 18:22

Hallo Michael,

gelöscht wird der Socket nur beim verlassen der module.php über

public function __destruct()
	{
		if ($this->Socket)
		    	socket_close($this->Socket);
	}

erzeugt wird er quasi „bei Bedarf“.

if (!$this->Socket)
			{
				// Socket erstellen
				if(!($this->Socket = socket_create(AF_INET, SOCK_STREAM, SOL_TCP))) {
					$errorcode = socket_last_error();
					$errormsg = socket_strerror($errorcode);
					//IPS_LogMessage("GeCoS_IO Socket", "Fehler beim Erstellen ".$errorcode." ".$errormsg);
					//$this->SendDebug("CommandClientSocket", "Fehler beim Erstellen ".$errorcode." ".$errormsg, 0);
					return;
				}

Wenn er noch besteht, wird er weiter benutzt. Bei sehr kurzen Zeiten zwischen den Anfragen besteht der Socket in der Regel noch.
Das GPS-Device sendet jede Sekunfen die aktuellen Daten, in der Regel so um die 500 Bytes. Ich kann ja zur Prüfung mal mitprotokollieren lassen, ob dann jedesmal ein neuer Socket erstellt wird. Das plötzlich keine Daten mehr vorliegen sollten, kann so nicht sein, weil zumindest die Anfrage an PIGPIO bestätigt wird und ggf. darin eine 0 für keine vorliegenden Daten zurückkommen müssten. Ansonsten ist es aber schon komisch, dass dieses immer wieder bei der gleichen Anzahl Anfragen/vergangener Zeit/ übertragenden Daten erfolgt.
Wenn es irgendeinen Buffer gibt, der dann einfach „voll“ ist, dann müsste ich vielleicht den Socket zwischendurch einmal gezielt alle x Anfragen „zerstören“?

Joachim

Nall-chan · 7. Oktober 2017 um 18:55

Dein Fehler liegt hier, wo du annimmst dass es ein Fehler ist, dabei sind nur keine Daten verfügbar (FALSE). Welches bei socket_strerror dann deine 11 ergibt. Dabei ist das kein Fehler


if(socket_recv ($this->Socket, $buf, $ResponseLen, MSG_WAITALL ) === FALSE)

Richtig ist es auf 0 zu prüfen, dann ist der socket ‚tot‘.

if(@socket_recv ($this->Socket, $buf, $ResponseLen, MSG_WAITALL ) === 0)

Erklärung:
PHP: socket_recv - Manual

Somit hast du einfach ‚Falschmeldungen‘ erzeugt.
Michael

JPaeper · 7. Oktober 2017 um 21:00

…habe das jetzt mal in meinem Code angepasst und einen neuen Testlauf gestartet. Ist jetzt bei knapp 7000 Anfragen - Ergebnis wird also noch etwas auf sich warten lassen. Trotzdem schon mal vielen Dank für Deinen Einsatz!

Joachim

JPaeper · 7. Oktober 2017 um 22:31

Hallo Michael,

das war es offenbar leider nicht: Auf Anfrage 12054 brach das Ganze wieder ab.
Es kommt zwar keine Fehlermeldung 11 mehr, aber diverse andere die mir zeigen das die Kommunikation zwischen IPS und PIGPIO gestört ist. Work-Around ist hier dann der Neustart von PIGPIo und IPS-Modul…

Werde jetzt mal versuchen den ClientSocket definiert zu einem Zeitpunkt neu starten zu lassen…

Joachim

Nall-chan · 7. Oktober 2017 um 22:35

Die Ursache ist ja ziemlich eindeutig, keine Daten im Eingangspuffer des Socket bedeutet das PIGPIO nicht antwortet.
Kann es sein, dass du zu viele Sockets gleichzeitig zu PIGPIO aufbaust, und es ihn dadurch zerlegt?
Michael

JPaeper · 7. Oktober 2017 um 22:39

…nach meinem Verständnis ist das nur einer…

In meinem Modul gibt es nur in der SplitterInstanz ein ClientSocket das zentral von allen Instanzen genutzt wird. Um die Performance zu erhöhen wird der aufgebaute ClientSocket jeweils dann geschlossen, wenn das Splitter-Skript verlassen wird.

Joachim

Nall-chan · 7. Oktober 2017 um 22:50

Quatsch, ich zitiere mich selbst:

Instanzen von PHP-Module sind nicht persistent. Es gibt keine eine Instanz.
Es gibt gar keine, erst wenn IPS etwas mit deiner Instanz machen muss, erzeugt es aus deine Klasse eine Objekt-Instanz.
Muss IPS das alle Sekunde machen, und dein ‚Script‘ welches IPS in deiner Klasse durchläuft braucht länger als eine Sekunde Laufzeit… Hast du bald zig PHP-Threads belegt und die gleiche Anzahl Objekt-Instanzen und Sockets.

Kannst du gerne unter den PHP-Threads nachschauen. Oder einfach mit SendDebug ausgeben wann ein Socket erzeugt und einer geschlossen wird.
Michael

JPaeper · 7. Oktober 2017 um 22:59

…also habe jetzt mal in den Debug schreiben lassen, wann ein Socket erzeugt bzw, gelöscht wird.
In der Tat ist es so, dass vor jedem Lesen der Daten ein ClientSocket erzeugt und danach wieder gelöscht wird…

Was die Thread-Belegung angeht sieht es eher übersichtlich aus zwei/drei von 15 sind irgendwie parallel aktiv…

Was heißt das denn jetzt?

Nall-chan · 7. Oktober 2017 um 23:08

Wie viele Verbindungen du parallel aufbaust bzw. aufgebaut hast kannst nur du ermittelt.
Entweder der PIGPIO hat einen Bug oder ist überlastet, weil er ist ja kein Webserver der auf viele gleichzeitige Verbindungen ausgelegt ist.
Du kannst das aber auch selbst entschärfen, indem du mit einer Semaphore verhinderst dass es mehr als einen Socket gibt. Nur verlängert sich da die Laufzeit.

Welcher Grund war es dass du nicht direkt auf den IPS-ClientSocket schreibst?
War der PIGPIO dort auch durcheinander gekommen, oder dein Modul?
Michael

JPaeper · 7. Oktober 2017 um 23:21

…nun in Wahrheit benutzte ich beide, den „eigenen“ und den von IPS.
Der eigene sendet Anfrage und empfängt das Ergebnis, der IPS-Socket ist ja dauert auf „Horchposition“ und empfängt besondere Benachrichtigungen (Events, Notifications, WatchDog etc. worauf ich dann in der Regel mit dem „eigenen“ Socket reagiere). theoretisch könnte man das wohl auch über den IPS-Socket alles machen, nur wird es dann sehr schwer die ganzen Daten auseinander zu bekommen zum anderen wird die Verarbeitung über zwei ClientSockets von Joan - dem Entwickler von PIGPIO - so empfohlen.

Ich werde das jetzt mal (wieder) mit dem Semaphore probieren. Hatte ich mal, hatte aber bisher keine Probleme festgestellt.

Aber wenn mein ClientSocket immer wieder geschlossen wird, wie kann es dann sein, dass seitens PIGPIO diese dann irgendwann „aufgebraucht“ sind? Meinst Du das mit „Bug“?

Nall-chan · 7. Oktober 2017 um 23:29

Jup, wenn er das nicht sauber erkennt, passiert so etwas gerne.
Oder auch, wenn er von zweien Redet, dann vielleicht auch wirklich nur zwei und nicht drei oder vier. Und das es dann kracht wenn viel in IPS für dein Modul zu tun ist (jemand mit einem Script die Outputs toggelt oder so )
Michael

JPaeper · 7. Oktober 2017 um 23:32

…schauen wir mal, Test läuft jetzt mit Semaphore auf 300ms, hoffentlich dann länger als 200 Minuten…

Danke nochmal für die Unterstützung!

Joachim

JPaeper · 8. Oktober 2017 um 08:26

…leider war diese Mal bei 8879 Anfragen das Ende erreicht…

Ich habe es jetzt noch mal im PIGPIO-Forum angefragt…

Joachim

JPaeper · 8. Oktober 2017 um 20:01

…ich habe mal den Speichergebrauch von PIGPIO vom Start bis zum „Absturz“ über top überwacht, er steigt von ca 11.000 beim Start bis über 3.000.000 - damit ist die These wohl (leider) bestätigt.

Nach meinem Kenntnisstand ist es aber aktuell nicht möglich, aus einem Splitter zwei übergeordnete ClientSockets (die dann ja kontinuierlich offen wären) seperat zu betreiben, oder?

Joachim

Nall-chan · 8. Oktober 2017 um 20:25

Nein geht nicht.
Melde das dem Entwickler als Bug.
Kann ja nicht sein, dass die SW dadurch abschmiert.
Michael