Neu Abgleich mit JTL Shop läuft nach zahlreichen erfolgreichen Durchläufen nicht mehr weiter

[vape-store]

Hallo zusammen,

ich habe das Problem, dass mein Worker nach zahlreichen erfolgreichen den Abgleich mit dem JTL Shop nicht mehr fortführt. Die Abgleiche mit den Connectoren und POS laufen problemlos weiter von dem Problem ist nur der JTL Shop betroffen.

Der Abgleich mit dem Shop läuft alle 5 Minuten. Der Abgleich dauert i.d.R. 1min. Der Abgleich läuft stundenlang alle 5 Minuten. Nach einer gewissen Zeit findet schlichtweg kein Abgleich mehr statt, bzw. ein Abgleich "hängt sich auf" und sorgt dafür, dass keine weiteren Abgleiche stattfinden.
Im Logbuch in JTL Wawi sehe ich, dass der Abgleich, der den Fehler verursacht hat, 54min gelaufen ist. Es ist jedoch kein Fehler im Logbuch. Die letzten Logs des problemverursachenden Durchlaufs sind im Screenshot "JTL-Wawi-Logbuch".

Im Logs im JTL Shop ist zum Fehlereintrittszeitpunkt die Fehlermeldung:
SyncException: 3
5.3.1
erkennbar. Auch hiervon ist ein Screenshot mit dem Namen "JTL-Shop-Fehlerlogs" angehängt.

Aktuell muss ich mehrmals täglich prüfen, ob der Worker noch läuft. Falls nicht, starte ich den Worker neu, anschließend läuft er wieder für wenige Stunden, bis sich der Fehler wiederholt.

Mein Setup:
JTL Wawi Version: 1.8.10
Datenbank und Worker laufen bei ecomData auf einer Windows 10 Maschine
Shop Version: 5.3.1
Der Shop läuft auf einem leistungsstarken Root-Server bei Hetzner. Die Shopdatenbank läuft auf demselben Server.

Ich bin sehr dankbar über jeden Hinweis, der mich zu einer Lösung für mein Problem führen könnte!!

Besten Dank vorab und viele Grüße

 

[NoOne]

SyncException: 3 heisst: Die Syncdaten sind falsch. Also Sync-Nutzer und/oder Sync-Passwort. Das könnte passieren, wenn der Server aus irgendeinem Grund die Anmeldedaten "unterschlägt". Oder ggf. einen 401 Forbidden zurückgibt. In diesem Fall wäre es auch sinnvoll zu schauen, was zu den Zeitpunkten im access_log und im error_log des Webservers steht. Wäre möglich das hier ein mod_security Problem vorliegt, oder das irgendwo eine maximale Anzahl an Verbindungen pro Stunde und pro IP (oder ähnliches) festgelegt ist und die IP für eine Weile gesperrt wird, wenn diese Anzahl überschritten wird.

 

[andiarbeit]

Habe das gleiche Problem seit gestern.

Ticket bei JTL. Bisher keine Antwort.

Habe schon überlegt ob es an dem neuen Lizenzmodell liegen kann. Evtl ist da irgendwas schief gelaufen

 

[bbfdesign]

Moin
Das Problem ist bei meinen Kunden früher auch schon des öfteren aufgetreten. Wie NoOne geschrieben hat, sollst Du im Shop mal ein neues Sync Passwort erstellen und dieses dann in der Wawi hinterlegen. Das führt aber nicht bei jedem Kunden zum Erfolg. Dann habe ich beobachtet, dass beim Abgleich etwas schief gelaufen ist, weswegen etwas defektes in den Syncdateien liegt. Prüfe doch mal via FTP ob in dem Shop unter dbeS/tmp das Verzeichnis leer ist oder ob da viele Dateien drin liegen. Wenn das der Fall ist, bereinige dieses Verzeichnis einmal.

Wenn beides nicht funktioniert, schreib gerne.

Gruß Björn

 

[vape-store]

Hallo,

vielen Dank für eure Hinweise.

Also wenn die Syncdaten falsch wären, dann dürfte ja gar kein Abgleich funktionieren. Es laufen aber alle 5 Minuten erfolgreiche Abgleiche, bis es zum Stillstand kommt. Habe jetzt dennoch das Sync Passwort geändert, die Verbindung getestet und den Worker nochmal gestartet. Mal schauen ob er erneut abbricht. Ich halte euch auf dem laufenden.

Der Ordner dbeS/tmp ist leer.

Zudem habe ich in die Logs vom Webserver geschaut und tatsächlich einen Fehler entdeckt. Zu Fehler-Ereigniszeitpunkt wurde das geloggt:
[proxy_fcgi:error] [pid 236145] (70007)The timeout specified has expired: [client <meine Server-IP>] AH01075: Error dispatching request to : (reading input brigade)
mehr steht nicht drin.

Laut Google Recherche soll ich den ProxyTimeout von standardmäßig 300s auf 600s erhöhen. Dazu habe ich in der apache2.conf folgendes hinzugefügt:
# ProxyTimeout legt fest, wie lange Apache auf eine Antwort vom Backend warten soll
# Wird die Zeit überschritten, gibt Apache einen Timeout-Fehler zurück.
ProxyTimeout 600

Das hat aber leider nicht geholfen, der Fehler ist nach dieser Änderung erneut aufgetreten.

Mein Server wird gemonitored, es gab zum Ereigniszeitpunkt keine Auffälligkeiten (hohe Auslastung oder ähnliches).

 

[NoOne]

Dazu müsste es auch einen entsprechenden Eintrag in der access_log, zur gleichen Zeit geben. Da wüsste man zumindest schon mal, welcher Aufruf die Ursache ist. Der Fehler klingt aber danach, als könnte ein Upload, der zu lange dauert, die Ursache sein. Ist zufällig auch mod_reqtimeout für Apache aktiv? Falls ja, dann sollte das mal probehalber deaktiviert werden.

 

[vape-store]

Der Fehler ist heute Nacht nach der Änderung des Sync Passworts erneut aufgetreten. Daran liegt es wohl nicht.

Hier die Access Logs:

Erfolgreicher Durchlauf:

185.214.191.103 - - [07/Sep/2024:03:56:31 +0200] "POST /dbeS/mytest.php HTTP/1.1" 200 2989
185.214.191.103 - - [07/Sep/2024:03:56:32 +0200] "POST /dbeS/GetKunden_xml.php HTTP/1.1" 200 373
185.214.191.103 - - [07/Sep/2024:03:56:32 +0200] "POST /dbeS/GetBestellungen_xml.php HTTP/1.1" 200 373
185.214.191.103 - - [07/Sep/2024:03:56:32 +0200] "POST /dbeS/GetZahlungen_xml.php HTTP/1.1" 200 373
185.214.191.103 - - [07/Sep/2024:03:56:33 +0200] "POST /dbeS/GetData_xml.php HTTP/1.1" 200 373
185.214.191.103 - - [07/Sep/2024:03:56:34 +0200] "POST /dbeS/lastjobs.php HTTP/1.1" 200 373

Fehlgeschlagener Durchlauf:

185.214.191.103 - - [07/Sep/2024:04:01:40 +0200] "POST /dbeS/mytest.php HTTP/1.1" 408 3060

Mehr Access Logs gibts zum Fehlgeschlagenen Durch lauf nicht.
Scheinbar wird beim Start des Abgleichs /dbeS/mytest.php aufgerufen. Dieser hat einen HTTP 408 Request Timeout Fehler geworfen.

Die /dbeS/mytest.php sieht so aus:

<?php // removed in 5.0.0

Die Erhöhung des Timeouts wird vermutlich nichts bringen, da die Ursache nicht bekämpft wird.

Übrigens: Einer meiner Connectoren läuft auf demselben Server mit einer ziemlich gleichen Apache2 Konfiguration. Ich vermute den Fehler daher weniger an der Server oder Apache2 Konfiguration, als vielmehr am Shop selbst.

 

[NoOne]

Mir würde nicht einfallen, warum der Shop einen 408er generieren sollte. Die /dbeS/mytest.php ist nur noch ein Platzhalter aus Kompatibilitätsgründen. Das wird in der .htaccess umgeleitet. 408 ist aber "Failed to process request in time". Das wird höchstwahrscheinlich vom Server geworfen. Eine Endlosschleife wäre eine Erklärung dafür, wenn die nicht vorher in einen Out-of-Memory-Error läuft. Allerdings wüsste ich jetzt so auf Anhieb nicht, was da vom Shop her schiefgehen soll. Instabile Netzwerkverbindung, vom Server verworfenes Paket, weil false positive (mod_security), oder zu restriktive Firewall wären auch mögliche Erklärungen. Wenn nicht alle Daten gesendet werden oder nicht rechtzeitig gesendet werden, dann tritt das auch auf.

 

[vape-store]

Ich habe ein Prometheus+Grafana Monitoring, das den Server stetig überwacht. Zum Zeitpunkt der Fehler gibt es keine Auffälligkeiten. Weder der Arbeitsspeicher noch die CPU-Daten zeigen anormale Ausschreitungen. Ich schließe daher einen Fehler auf dem Server aus.
Eine Firewall wird aktuell nicht eingesetzt.

Ich weiß leider echt nicht mehr weiter.

@NoOne Trotzdem vielen Dank für deinen Input. Du hast mich auf weitere Ideen gebracht (die leider auch nichts gebracht haben).

Ein Support Ticket ist bei JTL eingestellt. Sie schauen es sich jetzt an.

 

[frankell]

Habe das selbst und bei Kunden noch zu 1.8er-Zeiten (klingt, als wäre es ewig her) ebenfalls beobachtet. Da half noch nicht einmal, den Dienst manuell zu beenden und zu starten. Da half nur der Neustart der Maschine,

Aber: Seit 1.9.x nicht mehr aufgetreten.

Ich mag mich täuschen, aber da sich an den Servern, dem Shop und an der Wawi die Konfigurationen nicht geändert hatten, gehe ich von einem Bug aus, der iwann nach einem Update begann und ebenso nach einem Update wieder aufhörte zu existieren.

Hattest Du mal im IssueTracker geschaut, ob das Problem dort zu finden ist? Du bist oder warst auf jeden Fall nicht der Einzige, dem das widerfahren ist.

Ticket aufmachen ist aber auch auf jeden Fall richtig.

 

[mh1]

Mir würde nicht einfallen, warum der Shop einen 408er generieren sollte. Die /dbeS/mytest.php ist nur noch ein Platzhalter aus Kompatibilitätsgründen. Das wird in der .htaccess umgeleitet.

Ist denn mit dieser Umleitung in der .htaccess aller richtig?
Kannst du diese URL mit curl von prüfen (Parameter -i bzw. -I) ...und dann dazu entsprechend die acces_log und error_log beobachten.

408 ist aber "Failed to process request in time". Das wird höchstwahrscheinlich vom Server geworfen.

Der Server meldet mit dem Status Code 4xx Fehler, die vom Client verurschacht wurden.
Mit 408 sagt der Server, dass er eine Verbindung aufgrund eines Timeouts schließt. Das ist insofern schonmal ein Fehler, da der Client eine HTTP Verbindung schließen sollte und nicht der Server.

Ich würde mal die .htaccess prüfen.
Firewall bzw. Netzfilter und mod_security sind wie schon erwähnt auch Dinge, die man sich hier anschauen sollte.

 

[NoOne]

Der Server meldet mit dem Status Code 4xx Fehler, die vom Client verurschacht wurden.
Mit 408 sagt der Server, dass er eine Verbindung aufgrund eines Timeouts schließt. Das ist insofern schonmal ein Fehler, da der Client eine HTTP Verbindung schließen sollte und nicht der Server.

Technisch gesehen hast du recht. Der Fehler ist, dass die Verbindung so lange nicht geschlossen wird, bis der Server dazwischen grätscht. Wenn der Server die aber schließt, obwohl eine Rückantwort noch realistisch ist, dann ist das durchaus auch ein Fehler vom Server. Oder vielmehr, ggf. eine Fehlkonfiguration. Ist z.B. oft unpraktisch wenn die max_execution_time höher ist als der Request-Timeout. Wenn ein FPM die Verbindung aber kappt, obwohl die max_execution_time noch nicht abgelaufen ist, dann führt das auch zu Problemen.

Der idle-timeout könnte auch noch was sein, weil auch der was anderes ist als der request-timeout.

Es könnte auch durchaus sein, dass die Wawi nicht korrekt auf die Antwort von der mytest.php reagiert und die Verbindung nicht schließt. Oder dass auf dem Wawi-Rechner irgendwas verhindert, dass die Verbindung geschlossen wird oder ggf. der nächste Wawi-Request nicht zum Shop durchkommt und die Wawi dann "ewig" auf eine Antwort vom Shop wartet.

Da würde mich allerdings wundern, dass es immer erst nach einer gewissen Zeit aufzutreten scheint. Am Abgleich selbst sollte sich da eigentlich nichts ändern. Da wäre dann die Frage, ob es da irgendein Problem mit den temporären Dateien oder einem Cache (oder ähnlichem) der Wawi/des Workers gibt, was durch den Neustart dann erstmal wieder gelöst wird.