Update von 3.1.1 nach 3.1.2 schlägt fehl

    • Official Post

    Die libxml (die Grundbibliothek für XML-Verarbeitung in PHP) speichert eventuelle Fehler bei der Verarbeitung in einem externen Buffer zwischen. Um nun Fehler abzufragen bedarf es eines separaten Funktionsaufrufs in PHP libxml_get_errors(), sowie einem zweiten Aufruf libxml_clear_errors() um diesen Buffer zurückzusetzen. Wenn nun ein Fehler auftritt und es der Aufrufer den Buffer nicht zurücksetzt, dann wird bei der nächsten Abfrage des Buffers durch einen unbeteiligten Funktionsaufruf dieser Fehler zurückgeliefert. Dies ist vor allem dadurch ärgerlich, da man praktisch nur auf diese Weise einen Erfolgs- bzw. Fehlerfall eindeutig nachvollziehen kann.


    Ein Beispiel um es etwas anschaulicher zu gestalten:

    1. Funktion A ruft die libxml auf und verursacht einen Fehler.
    2. Funktion A ignoriert den Fehler und macht weiter.
    3. Funktion B ruft die libxml auf und es gibt keinen Fehler bei diesem Aufruf.
    4. Funktion B prüft den Fehlerbuffer von libxml, um festzustellen, ob es ein Problem gab.
    5. Im Buffer steht immer noch der Fehler vom Aufruf von Funktion A.
    6. Funktion B nimmt also an, dass der eigene Aufruf fehlgeschlagen ist und zeigt eine Fehlermeldung an.

    Das problematische an dieser Konstellation ist, dass Funktion B praktisch nicht feststellen kann, dass die Fehlermeldung eigentlich durch Funktion A verursacht wurde. In so einem Fall spricht man von einem "false-positive match", also eine Übereinstimmung, die gar keine ist. Dies wird verursacht durch den Sonderstatus der libxml in PHP (es gibt noch einige andere Beispiele), diese läuft mehr oder minder autark und kommuniziert nur über eine handvoll Funktionen mit PHP.


    Meine Vermutung an dieser Stelle ist, dass die Fehlermeldung von einer parallelen (bzw. vorhergehenden) PHP-Request stammt, die von der selben FastCGI-Instanz bearbeitet wurde. Heutzutage ist PHP-FPM sehr häufig anzutreffen und in diesem Konstrukt läuft PHP permanent und wartet auf neue Anfragen um diese zu beobachten, in Standardkonfigurationen werden tausende an Anfragen bearbeitet bevor eine Instanz neu gestartet wird. Theoretisch ist es denkbar, dass der libxml-Buffer an die Instanz gebunden ist und damit auch über die eigentliche Anfrage hinaus weiter existiert.


    Das ist aber auch alles mehr oder minder nur eine Theorie, denn es ging mir primär erstmal nur um einen work-around um das Problem zu umgehen. Selber konnte ich das Problem bisher leider noch nicht reproduzieren, die obige Erläuterung ist aber grundsätzlich schlüssig und liefert auf eine plausible Erklärung dafür, warum das Problem nur bei manchen auftritt. Allerdings hätte es in so einem Fall bereits vor 2 Jahren auftreten müssen, daher macht mich das plötzliche Auftreten etwas stutzig.


    Auf Grund der oben erwähnten isolierten Einbindung von libxml gibt es abseits von Gedankenexperimenten leider keinen wirklich belastbaren Weg um die Theorie eindeutig zu bestätigen. Mit der geänderten Fassung tritt das Problem aber nicht mehr auf und wird es auch zuverlässig nicht mehr tun, daher bin ich vorerst zufrieden und werde mir das in einer ruhigen Minute nochmal anschauen.

  • Meine Vermutung an dieser Stelle ist, dass die Fehlermeldung von einer parallelen (bzw. vorhergehenden) PHP-Request stammt, die von der selben FastCGI-Instanz bearbeitet wurde. Heutzutage ist PHP-FPM sehr häufig anzutreffen und in diesem Konstrukt läuft PHP permanent und wartet auf neue Anfragen um diese zu beobachten, in Standardkonfigurationen werden tausende an Anfragen bearbeitet bevor eine Instanz neu gestartet wird. Theoretisch ist es denkbar, dass der libxml-Buffer an die Instanz gebunden ist und damit auch über die eigentliche Anfrage hinaus weiter existiert.

    Sicher dass er nicht von euch selbst stammt ?

    Der HtmlInputProcessor und der HtmlOutputProcessor werfen ebide bei der Verarbeitung von custom HTML-Elementen Fehler ins libxml log und meines wissens führte es bisher bei allen Usern die eine eigene Datenschutzerklärung verwenden zu besagtem Fehler.

    Da das Update-Script nun ebenfalls zur validierung den vorhandenen Text einmalig verarbeitet liegt doch die Vermutung nahe dass hier das Problem im abweichenden Inhalt der Datenschutzerklärung zu finden ist die z.B. BBCodes in Form von woltlab-metacode einsetzen...

    • Official Post

    Da das Update-Script nun ebenfalls zur validierung den vorhandenen Text einmalig verarbeitet liegt doch die Vermutung nahe dass hier das Problem im abweichenden Inhalt der Datenschutzerklärung zu finden ist die z.B. BBCodes in Form von woltlab-metacode einsetzen...

    Das ist in der Tat eine plausible Erklärung und sie erklärt auch, weshalb dies nur bei manchen auftritt und kein allgemeines Problem darstellt. In meinen Tests habe ich die bestehende Datenschutzerklärung mehrmals bearbeitet um das Update zu testen, aber zu keinem Zeitpunkt kamen dort BBCodes oder vergleichbares vor.


    Manchmal sieht man den Wald vor lauter Bäumen nicht, vielen Dank für den Hinweis!

  • Dragosius Der Fix ist doch schon raus.


    Eine modifizierte Fassung des Updates ist nun über die Update-Server verfügbar, es enthält einen work-around für das Problem.


    Habe einmal den Cache geleert, dann 2-3 mal nach Updates suchen lassen, danach klappte das Update. ;)

    Hab mich jetzt mal selbst Zitiert. ;)

    Greetz

    Dark


    Nach dem Update ist vor dem Update. :S

  • Also ich konnte nach löschen der Caches alle meine Installationen updaten (sind ein paar :) )(Version zeigt jedoch kein Patchlevel an, wie hier).


    Ohne Cache löschen hats jedoch nie geklappt

    Viele Grüsse aus Stuttgart, Kind Regards from Stuttgart
    TheSonic

  • Also bei mir sieht es so aus das beim Update auf 3.1.2 pl 2 zwar versucht wird zu installieren aber nach einiger Zeit kommt die 500er Seite.

    Cache geleert, Conjob Paketinformationen aktualisiert.


    Hab mal ein paar Bilder angehängt.


  • Komplett anderer Fehler für den du schauen musst was im Server log steht.

    im error-log steht folgendes.

    Code
    [Mon Apr 23 12:13:49 2018] [warn] [client xxx.xxx.xxx.xxx] mod_fcgid: read data timeout in 45 seconds, referer: https://tc-schwabach-radio.de/acp/index.php?package-update/
    [Mon Apr 23 12:13:49 2018] [error] [client xxx.xxx.xxx.xxx] Premature end of script headers: index.php, referer: https://tc-schwabach-radio.de/acp/index.php?package-update/
  • Scheinbar ist das Update in einen Timeout gelaufen, wirklich was daran ändern lässt sich daran nichts.

    Einfach nochmal versuchen...

  • im error-log steht folgendes.

    Code
    [Mon Apr 23 12:13:49 2018] [warn] [client xxx.xxx.xxx.xxx] mod_fcgid: read data timeout in 45 seconds, referer: https://tc-schwabach-radio.de/acp/index.php?package-update/
    [Mon Apr 23 12:13:49 2018] [error] [client xxx.xxx.xxx.xxx] Premature end of script headers: index.php, referer: https://tc-schwabach-radio.de/acp/index.php?package-update/

    Du nutzt Plesk... hast du Apache und nginx als Proxy am laufen...? Da kam ich es bei einer früheren Installation auch zu so einem Fehler... Ich habs nicht weiter nachvollzogen - nochmal neu gestartet und alles war danach ok, sowohl im laufenden Betrieb, wie auch bei den nächsten Updates.


    Schau, ob alle Dienste laufen (apache, nginx, MariaDB/MySQL und ggfs. die entsprechende PHP-FPM-Instanz.)

    Viele Grüsse aus Stuttgart, Kind Regards from Stuttgart
    TheSonic