Aufruf Server-Dienst-Verwaltung extrem langsam [GELÖST]

[tab-kh]

Ich habe vor einiger Zeit (01.08.2021) einen neuen vServer von netcup (RS 2000 G9) in Betrieb genommen. KVM Virtualisierung, 4 Cores, 16GB RAM. Installiert ist Debian 10 und die aktuelle Keyhelp-Version. Momentan läuft da irgendwas schief und ich finde keine Ursache. Ich kann nicht ausschliessen, dass das von Anfang an so war, da ich die Server-Dienst-Verwaltung bisher wahrscheinlich gar nicht aufgerufen hatte. Es äußert sich so, dass manche Dinge sehr langsam sind. Auffällig ist besonders der Aufruf der Server-Dienst-Verwaltung im Keyhelp Panel, das dauert mindestens 30 Sekunden, manchmal auch ca 60 oder 90 Sekunden, bis die Seite aufgebaut ist. Andere Punkte im Keyhelp Panel sind weniger oder gar nicht betroffen, auffällig ist allenfalls noch die Zeit beim Aufruf der Bearbeitung von Domains. Der Punkt Domains selbst ist unauffällig, nur wenn ich eine Domain zum Bearbeiten anklicke, dauert es so 3-6 Sekunden, bis die entsprechende Seite angezeigt wird. Im Apache-Log und im access.log gibt es auch nichts Auffälliges, bis eben auf das Offensichtliche, dass die Requests lange dauern.

Meine beiden anderen Server, ebenfalls von netcup, laufen seit Monaten mit Keyhelp sehr zuverlässig und unauffällig. Sie zeigen dieses Verhalten auch nicht. Möglicherweise liegt es am vServer, ich werde heute auch mal auf den Servern sysbench laufen lassen und die Ergebnisse untereinander vergleichen. Vielleicht gibt es da ja Auffälligkeiten.

[tab-kh]

Mit den einkompilierten Tests von Sysbench bin ich durch und habe die Werte jeweils mit einem der anderen Server verglichen. Hierbei ist nichts Auffälliges rausgekommen, der Server ist fast allen Tests etwas schneller als die anderen und bei keinem wirklich langsamer. Ich mache mich jetzt mal an die Datenbanken, vielleicht ist ja eine Tabelle oder ein Index kaputt. Ansonsten bliebe noch die Netzwerkanbindung, allerdings zeigen die Entwicklertools von FF keine Hinweise darauf. Die Verbindung kommt beim Request sehr schnell zustande, dann wird gewartet ... und Stunden später kommen dann erst die Daten.

Auch in die /var/log/keyhelp/php-error.log habe ich mal reingeschaut und hier etwas Auffälliges gefunden. Hier der komplette Inhalt, ist nicht viel.

Code: Select all

[01-Aug-2021 21:02:02 Europe/Berlin] PHP Warning:  MySQL - Connection Error: 2002 (No such file or directory) in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 286
[01-Aug-2021 21:02:02 Europe/Berlin] PHP Warning:  mysqli::query(): Couldn't fetch mysqli in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 86
[01-Aug-2021 21:02:02 Europe/Berlin] PHP Warning:  mysqli::query(): Couldn't fetch mysqli in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 87
[01-Aug-2021 21:02:02 Europe/Berlin] PHP Warning:  mysqli::query(): Couldn't fetch mysqli in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 88
[01-Aug-2021 21:02:02 Europe/Berlin] PHP Warning:  mysqli::query(): Couldn't fetch mysqli in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 111
[01-Aug-2021 21:02:02 Europe/Berlin] PHP Warning:  DBConnection::query(): Couldn't fetch mysqli in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 112
[01-Aug-2021 21:02:02 Europe/Berlin] PHP Warning:  mysqli::ping(): Couldn't fetch mysqli in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 122
[01-Aug-2021 21:02:03 Europe/Berlin] PHP Notice:  DB-Connection timed out, now reconnecting... in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 131
[01-Aug-2021 21:02:03 Europe/Berlin] PHP Warning:  mysqli::close(): Couldn't fetch mysqli in /home/keyhelp/www/keyhelp/core/pending/DBConnection.php on line 93
[08-Aug-2021 06:24:54 Europe/Berlin] PHP Warning:  file_put_contents(/etc/awstats/awstats.meinuser.conf): failed to open stream: Read-only file system in /home/keyhelp/www/keyhelp/cronjob/jobs/statistic.php on line 504
[15-Aug-2021 06:24:57 Europe/Berlin] PHP Warning:  file_put_contents(/etc/awstats/awstats.meinuser.conf): failed to open stream: Read-only file system in /home/keyhelp/www/keyhelp/cronjob/jobs/statistic.php on line 504
[22-Aug-2021 06:24:51 Europe/Berlin] PHP Warning:  file_put_contents(/etc/awstats/awstats.meinuser.conf): failed to open stream: Read-only file system in /home/keyhelp/www/keyhelp/cronjob/jobs/statistic.php on line 504
[29-Aug-2021 06:25:16 Europe/Berlin] PHP Warning:  file_put_contents(/etc/awstats/awstats.meinuser.conf): failed to open stream: Read-only file system in /home/keyhelp/www/keyhelp/cronjob/jobs/statistic.php on line 504

Die Fehler vom 01.08.21 sind vom Tag der Keyhelp-Installation, allerdings habe ich die bereits kurz nach Mittag durchgeführt, sie dürften also nicht von der Installation herrühren. Möglicherweise habe ich mich dann erst abends an die Einrichtung gemacht, also Benutzer/Domains etc. angelegt.

Edit: Die wöchentlichen Fehler habe ich auf den anderen Servern auch, die haben also wohl zumindest mit diesem Problem nichts zu tun.

[tab-kh]

Da sucht man stundenlang und dann löst sich das Ding in Luft auf. Gerade eben nochmal die Server-Dienst-Verwaltung aufgerufen, kommt genauso schnell wie bei den anderen Servern. Keine Ahnung was das gewesen ist, möglicherweise doch ein Providerproblem.

[tab-kh]

Und genauso anscheinend anlasslos ist das Problem jetzt wieder da.

[Tobi]

Dann mach mal ein tracert auf deine URL.

[BloodOfPanda]

Hey tab-kh,

ich bin nicht mal sicher ob es an KH liegt oder an NC, ich hab das seit zwei/drei tagen auch das es wirklich länger dauert bis das ganze da ist und in der nächsten Stunde rennt das ganze wieder und ich hatte bisher noch kein Problem mit meiner KH Instanz.

Grüße Panda // Marcel

[tab-kh]

@tobi: tracert von meinem PC auf den Servernamen oder wie meinst du das?

Hey tab-kh,

ich bin nicht mal sicher ob es an KH liegt oder an NC, ich hab das seit zwei/drei tagen auch das es wirklich länger dauert bis das ganze da ist und in der nächsten Stunde rennt das ganze wieder und ich hatte bisher noch kein Problem mit meiner KH Instanz.

Grüße Panda // Marcel

Naja, ich hab ja 3, davon funktionieren gleichzeitig 2, während der dritte nur Probleme macht. Heute abend kurz bevor ich weg musste, hatte ich das Panel einfach eine Weile laufen, angezeigt wurde die ServerDienst-Verwaltung und ich musste derweilen einige Minuten was anderes tun. Als ich zurück zum Rechner kam, hatte ich einen Fehlerscreen (Ich glaube 503) mit dem Text, dass der Server im Wartungsmodus oder überlastet sei. Ich muss mal schauen, ob da was an der Apache oder PHP-FPM Konfiguration klemmt oder warum sonst die Bearbeitung dieses Request so lange dauert. Der Apache mag überlastet sein, der vServer sicher nicht. Über 10% CPU kommt der währenddessen kaum, auch RAM ist mehr als ausreichend vorhanden. Da läuft ja nichts außer dem Panel, der momentan einzige "Kunde" bin ich und ich mache nichts währenddessen. Also höchstens noch ein paar Russen, Chinesen, Israelis und Amerikaner, die versuchen sich anzumelden ohne Key. Ich muss mir morgen mal die Apache error-logs und access-logs von der Zeit und überhaupt genau durchschauen. Und eventuell mal den MariaDB-Server und die Datenbanken durchchecken. Ansonsten setze ich das Ding einfach wieder auf Null und installiere neu. Von den anderen Servern, alle ebenfalls netcup, mit den gleichen netcup-Resolvern, die wohl nicht immer so furchtbar zuverlässig funktonieren, kenne ich derlei Probleme überhaupt nicht. Und die haben im Gegensatz zu diesem Server mittlerweile zumindest schon etwas Last.

[Tobi]

Tracert als Abkürzung von traceroute.

Ja, in der Tat ein trace von deiner Arbeitsstation zu deinem Server. Alternativ mal mit dem Handy über das. Mobilfunknetz testen und vergleichen.

Selbst wenn deine Server alle bei Netcup sind, kann der Weg der Daten ein unterschiedlicher sein.
Es reicht ein defekter / überlasteter Switch und schon gibts Probleme.

[tab-kh]

Hier isses:

Hier der fragliche Server

Code: Select all

  1     1 ms     1 ms     1 ms  2a02:8070:278f:6c00:ae22:5ff:fea9:331
  2    10 ms    10 ms     9 ms  2a02:8070:2700::1
  3    17 ms     8 ms     7 ms  2a02:8070:20ff:2885::1
  4    12 ms    18 ms    13 ms  de-fra01b-rc2-lo0-0.v6.aorta.net [2001:730:2d00::5474:8065]
  5    19 ms    11 ms    11 ms  ae3-1337.bbr02.anx25.fra.de.anexia-it.net [2001:7f8::a5e9:0:3]
  6    27 ms    22 ms    18 ms  2a00:11c0:47:1:47::140
  7    79 ms    13 ms    14 ms  2a00:11c0:47:3::21
  8    14 ms    24 ms    13 ms  mein.server.de [2a03:4000:xx:xxx:c872:5ff:fe4a:8ed7]

Hier der "funktionierende" Server

Code: Select all

  1     1 ms     1 ms     1 ms  2a02:8070:278f:6c00:ae22:5ff:fea9:331
  2     9 ms     9 ms     8 ms  2a02:8070:2700::1
  3     8 ms     7 ms     8 ms  2a02:8070:20ff:2885::1
  4    13 ms    20 ms    26 ms  de-fra01b-rc2-lo0-0.v6.aorta.net [2001:730:2d00::5474:8065]
  5    16 ms    16 ms    16 ms  ae3-1337.bbr02.anx25.fra.de.anexia-it.net [2001:7f8::a5e9:0:3]
  6    14 ms    14 ms    15 ms  2a00:11c0:47:1:47::140
  7    32 ms    21 ms    22 ms  2a00:11c0:47:3::21
  8    13 ms    14 ms    13 ms  anderer.server.de [2a03:4000:xx:xxx:44a:aeff:fe54:f13b]
  

Auch der dritte Server hat exakt die gleichen Hops.

Edit: Wenn ich im Browser in den Entwicklertools schaue, dann wird die Verbindung zum Server relativ schnell hergestellt, die restliche Zeit ist "Warten".

Code: Select all

Anfrage-Zeiten
Blockiert:
53 ms
DNS-Auflösung:
0 ms
Verbindungsaufbau:
17 ms
TLS-Konfiguration:
26 ms
Senden:
0 ms
Warten:
1,10 min
Empfangen:
0 ms

Edit2: Hier die URL, die aufgerufen wird, naja, fast.
https://mein.server.de/index.php?page=admin_services&sid=jjkcrplhexxxxxxxxxx3as1hss

[Tobi]

Nun gut, dann liegt es zumindest NICHT an der Anbindung.

[tab-kh]

Momentan ist es wieder weg ...

Ich habe auch einen Fehler in meiner Konfiguration gefunden, von dem ich mir nicht sicher bin, ob er das bewirken könnte. Ich hatte versehentlich die Subdomain für den Kundenzugang zum Panel im Zuge der Umstellung einer Testdomain auf PHP 8 ebenfalls auf PHP 8 gestellt, was natürlich nicht funktionieren kann. Die Frage wäre allerdings, ob dies den Effekt erklären könnte, auch wenn ich mich nie über diese Subdomain anmelde. Ich bin ja momentan der einzige Kunde auf dem Server und wenn ich da was verstelle, gehe ich über das Adminpanel und die Benutzerverwaltung in mein Kundenpanel. Ich habe das jetzt auf die Systemversion von PHP zurückgestellt und werde die Sache jetzt mal ohne weitere Änderungen beobachten, einen Tag oder bis das Problem trotzdem wieder auftritt .

[BloodOfPanda]

Hallöchen ich nochmal

Dieses Problem ist mir erst aufgefallen nachdem ich die Tage meine Domain auch über IPv6 erreichbar gemacht habe.
Ggf. liegt ja hier der Zusammenhang, laufen denn deine anderen Server auch auf IPv6 bzw. erreichbar?

Code: Select all

  1     3 ms     2 ms     2 ms  fritz.box [2a02:2454:b1d:c900:de15:c8ff:fe37:7ec9]
  2     9 ms     8 ms    10 ms  2a02-2454-0-2a--1.dyn6.pyur.net [2a02:2454:0:2a::1]
  3     *        *        *     Zeitüberschreitung der Anforderung.
  4    18 ms    19 ms    17 ms  2a02-2454-78--3a1.dyn6.pyur.net [2a02:2454:78::3a1]
  5   127 ms   131 ms   122 ms  2a02:238:1:f016::1
  6   148 ms    60 ms    91 ms  ipv6.de-cix.fra.de.as16097.hlkomm.net [2001:7f8::3ee1:0:2]
  7    30 ms    31 ms    37 ms  ae3-1337.bbr02.anx25.fra.de.anexia-it.net [2001:7f8::a5e9:0:3]
  8   116 ms   101 ms    96 ms  2a00:11c0:47:1:47::140
  9   151 ms   168 ms    47 ms  2a00:11c0:47:3::21
 10    90 ms   104 ms   137 ms  mein.server.de [2a03:xxxx:13:xxx:xxxx:xxxx:xxxx:2a22]

[tab-kh]

Ja, die sind beide über IPv4 und IPv6 erreichbar. Momentan ist noch Ruhe, alles läuft normal. Mir ist halt aufgefallen, dass ca um die Zeit, wo gestern Abend der Fehler 503(?) kam, in /var/log/apache2/error.log drin steht, dass der Apache sich zweimal neu gestartet hat und auch Probleme mit Zertifikaten hatte. Später habe ich dann gesehen, dass in /var/log/apache2/keyhelp ebenfalls noch eine error.log drin ist. Da waren zur selben Zeit zwar andere, aber eben auch Fehlermeldungen drin. Vorhin habe ich dann um 11:43 und 11:45 die Änderungen an der Kundendomain gemacht. Jetzt ist die Einstellung diesr Kundendomain identisch zu den anderen Servern. Also

Lokales Verzeichnis: /www/
keine Maildomain
nicht deaktiviert
DNS deaktivieren angehakt
Lets Encrypt Zertifikat und sichere Verbindung erzwingen
Interpreter: Standard - PHP 7.3.29

In der /var/log/apache2/error.log von heute habe ich um 11:44 und 11:46 Fehlermeldungen

Code: Select all

[Tue Aug 31 11:44:02.216906 2021] [mpm_worker:notice] [pid 1865:tid 140248966145152] AH00297: SIGUSR1 received.  Doing graceful restart
[Tue Aug 31 11:44:02.276517 2021] [ssl:warn] [pid 1865:tid 140248966145152] AH01909: webmail:443:0 server certificate does NOT include an ID which matches the server name
[Tue Aug 31 11:44:02.276646 2021] [ssl:error] [pid 1865:tid 140248966145152] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: emailAddress=info@keyhelp.de,CN=mein.server.de,OU=KeyHelp Panel,O=KeyHelp,L=Erfurt,ST=Thuringia,C=DE / issuer: emailAddress=info@keyhelp.de,CN=mein.server.de,OU=KeyHelp Panel,O=KeyHelp,L=Erfurt,ST=Thuringia,C=DE / serial: 135CXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX48A7 / notbefore: Aug  1 12:44:50 2021 GMT / notafter: Jul 30 12:44:50 2031 GMT]
[Tue Aug 31 11:44:02.276653 2021] [ssl:error] [pid 1865:tid 140248966145152] AH02604: Unable to configure certificate webmail:443:0 for stapling
[Tue Aug 31 11:44:02.280371 2021] [mpm_worker:notice] [pid 1865:tid 140248966145152] AH00292: Apache/2.4.38 (Debian) mod_fcgid/2.3.9 OpenSSL/1.1.1d configured -- resuming normal operations
[Tue Aug 31 11:44:02.280381 2021] [core:notice] [pid 1865:tid 140248966145152] AH00094: Command line: '/usr/sbin/apache2'
[Tue Aug 31 11:46:02.079873 2021] [mpm_worker:notice] [pid 1865:tid 140248966145152] AH00297: SIGUSR1 received.  Doing graceful restart
[Tue Aug 31 11:46:02.613695 2021] [ssl:warn] [pid 1865:tid 140248966145152] AH01909: webmail:443:0 server certificate does NOT include an ID which matches the server name
[Tue Aug 31 11:46:02.613799 2021] [ssl:error] [pid 1865:tid 140248966145152] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: emailAddress=info@keyhelp.de,CN=mein.server.de,OU=KeyHelp Panel,O=KeyHelp,L=Erfurt,ST=Thuringia,C=DE / issuer: emailAddress=info@keyhelp.de,CN=mein.server.de,OU=KeyHelp Panel,O=KeyHelp,L=Erfurt,ST=Thuringia,C=DE / serial: 135CXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX48A7 / notbefore: Aug  1 12:44:50 2021 GMT / notafter: Jul 30 12:44:50 2031 GMT]
[Tue Aug 31 11:46:02.613805 2021] [ssl:error] [pid 1865:tid 140248966145152] AH02604: Unable to configure certificate webmail:443:0 for stapling
[Tue Aug 31 11:46:02.617440 2021] [mpm_worker:notice] [pid 1865:tid 140248966145152] AH00292: Apache/2.4.38 (Debian) mod_fcgid/2.3.9 OpenSSL/1.1.1d configured -- resuming normal operations
[Tue Aug 31 11:46:02.617451 2021] [core:notice] [pid 1865:tid 140248966145152] AH00094: Command line: '/usr/sbin/apache2'

Ich nehme an, der Grund für den Neustart des Apache sind meine jeweiligen Änderungen an der Subdomain, also planmässige Neustarts.
Passend zu den aus dem Log hervorgehenden Zertifikatsproblemen der webmail-Subdomain:
Bei Aufruf von "https://webmail.mein.server.de" bekomme ich die bekannte gelb umrahmte Seite von Firefox, http://webmail.mein.server.de dagegen wird klaglos mit Status 302 auf https://mein.server.de/webmail weitergeleitet.

[tab-kh]

Das war es auch nicht, das Problem ist jetzt wieder aufgetreten. Ich weiss jetzt aber zu 99% woran es liegt. Tatsächlich an den netcup Resolvern! Und das, obwohl alle drei Server die selben Resolver verwendet haben und zwei davon dieses Problem nie gezeigt haben. Während der betroffene Server noch versucht hat, die Server-Dienst-Verwaltung zu laden, habe ich mich am anderen Server am Panel angemeldet und problemlos die Server-Dienst-Verwaltung geladen, bevor der erste Server noch damit fertig war. Deswegen dachte ich eigentlich, dass die Resolver als Ursache nicht in Betracht kommen, obwohl ich wusste, dass es da derzeit große Probleme gibt.

Offenbar ist es wohl tatsächlich so, dass nicht alle Server mit den Resolvern Probleme (Timeouts) haben. Weil ich einfach keine andere Idee mehr hatte, woran es noch liegen könnte und die Resolver endgültig als Ursache ausschliessen wollte, habe ich testhalber die Google Resolver eingetragen. Und sofort konnte ich die Server-Dienst-Verwaltung ganz normal aufrufen! Mehrfach probiert, kein Problem. Wieder die netcup-Resolver eingetragen und das Problem war wieder da. Das Spiel habe ich dann einige Male gemacht, um halbwegs sicher zu sein, dass es auch daran liegt und nicht nur Zufall war. Jedes Mal dasselbe, mit Google-Resolvern alles gut, mit netcup-Resolvern Probleme. Ich lasse jetzt erst mal Google drin, bis netcup das Resolver-Problem gefixt hat.

Interessieren würde mich ja nur noch, warum nur die Server-Dienst-Verwaltung betroffen ist und in sehr geringem Umfang wohl auch das Bearbeiten von Domains. Da geht es aber nur um ein paar Sekunden. Alles andere, soweit ich es probiert habe, lässt sich problemlos und flüssig öffnen.