Probleme mit Apache 2.0.x, mod_fcgid und php5

[theomega]

Hallo Leute,
ich habe riesige Probleme mit einem FastCGI-GEspann aus apache 2.0.x und PHP5. Momentan ist als MOdul mod_fcgid installiert. Es funktioniert meistens gut, nur manchmal erhalten die Benutzer 500erter Errors (Internal Server errors).
Die Logdateien zeigen zu diesem Zeitpunkt folgende Einträge

1. Error-Log-Datei vom VHost:

Code: Select all

[Mon Jan 15 15:20:21 2007] [warn] mod_fcgid: can't apply process slot for /pfad/zum/php/script.php
[Mon Jan 15 15:20:22 2007] [warn] mod_fcgid: can't apply process slot for /pfad/zum/php/script.php

2. Error-Log-Datei vom Apache:

Code: Select all

[Mon Jan 15 15:20:24 2007] [notice] mod_fcgid: process /pfad/zum/php/script.php(22050) exit(communication error), terminated by calling exit(), return code: 0
[Mon Jan 15 15:20:24 2007] [notice] mod_fcgid: process /pfad/zum/php/script.php(22039) exit(communication error), terminated by calling exit(), return code: 0
[Mon Jan 15 15:20:28 2007] [notice] mod_fcgid: process /pfad/zum/php/script.php(22061) exit(communication error), terminated by calling exit(), return code: 0

Meine Konfiguration sieht wie folgt aus:
- Gentoo unstable hardened
- Apache/2.0.59
- mod_fcgid 2.0
- PHP 5.1.6-pl8-gentoo with Hardening-Patch 0.4.15

Konfigurationsdateien:
1. mod_fcgid.conf

Code: Select all

<IfDefine FCGID>
    <IfModule !mod_fcgid.c>
        LoadModule fcgid_module modules/mod_fcgid.so
    </IfModule>
    <IfModule mod_fcgid.c>
        AddHandler fcgid-script .fcg
        BusyTimeout 60
        IPCCommTimeout 60
        MaxRequestsPerProcess 440
        IdleTimeout 120
        IdleScanInterval 60
    </IfModule>
</IfDefine>

2. VHost:

Code: Select all

        <Directory "/srv/vhost/html">
                Options -All +FollowSymlinks +ExecCGI
                AllowOverride AuthConfig FileInfo Indexes Limit Options
                Order allow,deny
                Allow from all
                AddHandler fcgid-script .php
                FCGIWrapper /srv/php-fcgi-scripts/vhost/php-fcgi-starter .php
        </Directory>


<VirtualHost *:80>
        ServerName pagenstecher.de
        DocumentRoot "/srv/vhost/html/seite"


        SuexecUserGroup vhost www-users

        ErrorLog /srv/vhost/logs/error_log
        CustomLog /srv/vhost/logs/access_log combined
</VirtualHost>

3. php-fcgi-starter:

Code: Select all

#!/bin/sh
PHPRC="/srv/pagenstecher/conf"
export PHPRC
PHP_FCGI_CHILDREN=10
export PHP_FCGI_CHILDREN
exec /usr/bin/php-cgi

Komisch ist auch: "pstree -up" zeigt mir immer wieder eingie Prozesse an, die als "Eltern" nur den init-prozess haben, was ja eigentlich nicht passieren sollte, denn normalerweise (und so ist es auch bei fast allen php-cgi-prozessen) sollten die ja dem apache "gehören". Diese Prozesse tun auch rein garnichts und ich kille sie dann immer mal wieder.


Wer hat mir irgendeinen Tipp wo ich anfangen kann zu suchen? Kann man PHP irgendwie zu Debug-Ausgaben überreden?

Danke
TO

[kase]

Den Log-Level vom Apache auf "debug" stellen, falls nicht schon geschehen. fcgid versteckt im Level debug teilweise sehr nützliche Fehlermeldungen.

Außerdem evtl die IPCConnectTimeout n (3 seconds) etwas höher stellen, glaube zwar nicht, dass es hilft, aber einfach mal probieren, so 10 oder so.

[theomega]

Hy,
danke für den Tipp, aber es bringt nichts. Allerdings habe ich die Sache deutlicher analyisiert: IN unregelmäßigen Abständen hängen ALLE FastCGI's, niemand bekommt dann eine antwort. In den Logs steht dann:

Code: Select all

[Tue Jan 16 21:47:51 2007] [info] mod_fcgid: /ph/p/f/ile.php spawn score 10 >= 10, skip the spawn request

extrem oft

Code: Select all

[Tue Jan 16 21:47:56 2007] [notice] mod_fcgid: process /php/file/date.php(30723) exit(communication error), terminated by calling exit(), return code: 0

oft (vermutlich für jeden Proezss einmal)


Zusätzlich zu diesen Meldungen treten im MOment andauernd (Also auch wenn die Seite nicht hängt fehler dieser Art auf:

Code: Select all

[Tue Jan 16 23:39:11 2007] [info] [client 4.254.219.207] (104)Connection reset by peer: core_output_filter: writing data to the network
[Tue Jan 16 23:39:11 2007] [info] [client 4.254.219.207] (32)Broken pipe: core_output_filter: writing data to the network

Ich finde im Internet nichts dazu, ist der FEhler normal?

Danke schonmal
TO

[Roger Wilco]

Ohne jetzt genau in die Tiefen von mod_fcgid hinabzutauchen: mod_fcgid verwaltet die Forkanzahl bzw. die Forkgeschwindigkeit der Prozesse über ein Scoreboard. Wenn ein bestimmter Wert erreicht wird (in deinem Fall 10), erfolgen die weiteren Forks bis zum Prozessmaximum nur noch verzögert, bis die bereits laufenden Requests verarbeitet wurden und sich der Score wieder verringert.

Schau dir unter http://fastcgi.coremail.cn/doc.htm mal die Direktiven SpawnScoreUpLimit, SpawnScore und TerminationScore an und spiel mit deren Werten rum.

[kase]

Wieviel php-fcgi Prozesse hast du denn nach einiger Zeit?

Da scheinbar der vHost ziemlich viele Hits hast, könntest du auch mal deine PHP_FCGI_CHILDREN=10 erhöhen, wenn genug Ram in der Maschine ist, sollte da ein Wert von 20-25 ohne Probleme möglich sein, so dass von Anfang an mehr Prozesse zur Verfügung stehen.

[theomega]

Also das problem mit dem spawnlimit ist nicht die ursache sondern die auswirkung. Zumindest scheint es so. Zu diesem Zeitpunkt (Also wenn die Seite hängt habe ich über 2000 php-cgi Prozesse und er erstellt immer neue), manchmal fängt es sich nach ein Paar Minuten wieder, meistens muss ich dann aber den Apache stoppen, alle PHP-Prozesse killen und den Apache wieder starten. Unter normalen Umständen habe ich ungefähr 320 PHP-CGI-Prozesse (mit ps aux feststellt). Ich werde einfach mal die CHildsanzahl erhöhen. RAM wären 2GB, das sollte doch eigentlich weit reichen.

[theomega]

Die Situation verschlimmert sich enorm wenn ich die Anzahl der Childs auf 20 stelle: Es werden pro Minute ungefähr 100 Prozesse erstellt die plötzlich NIEMANDEM mehr gehören, also im PS-Tree unterhalb des Inits stehen. Der fastcgid verliert also total die Kontrolle und es werden immer mehr Prozesse. Dementsprechend steigt der Load in den Himmel. Hat dazu jemand eine Idee?

[kase]

Das Problem ist, dass fcgid einfach viel zu viele Prozesse spawnt.

Selbst 320 php-fcgi Prozesse, das ist einfach nur heftig.

Ich habe die Vermutung, dass fcgid merkt, es reicht nicht, und dann nicht zB 10 neue Prozesse spawnt, sondern PHP_FCGI_CHILDREN*10 neue Prozesse. Das ganze läuft dann irgendwann Amok.

Was du auf jeden Fall probieren könntest, wäre im php-fcgi-starter

PHP_FCGI_CHILDREN=10
export PHP_FCGI_CHILDREN

mal komplett herauszunehmen und schauen, was passiert. Das hat auch damals schon bei mod_fastcgi solche Probleme oftmals gelöst.

[kase]

Ich bin mir inzwischen sogar recht sicher...

Lass folgende Zeilen aus deinem php-fcgi-starter raus:

PHP_FCGI_CHILDREN=10
export PHP_FCGI_CHILDREN

Habe etwas mit AB rumgespielt, fcgid war wesentlich performanter ohne PHP_FCGI_CHILDREN zu setzen.

Ich denke inzwischen, dass PHP_FCGI_CHILDREN noch eine Altlast aus den Anfängen von fastcgi war, weil die entsprechenden Apache-MODS dafür noch Probleme mit dem Prozess-Spawning hatten. Bei Lighthttpd braucht man zB noch die PHP_FCGI_CHILDREN Variable, weil man dort (zumindest bei Konfiguration unter entsprechenden Users und nicht als www-data, siehe Howto http://trac.lighttpd.net/trac/wiki/HowT ... ermissions ) nur den Socket der php-fcgi-Prozesse angibt, sprich das Prozess-Management übernimmt nicht das fastcgi-Modul sondern php selbst.

Ohne PHP_FCGI_CHILDREN spawnt php nur einen einizigen Prozess, fcgid erhöht die Anzahl der Prozesse dann entsprechend der Last. Bei 100 konkurrenten Usern habe ich am Ende 20 Prozesse.

Mit PHP_FCGI_CHILDREN=20 macht fcgid GENAU DAS GLEICHE, und genau das ist das Problem. Bei ebenfalls 100 konkurrenten Usern habe ich dann am Ende 350 php-fcgi-Prozesse, das System wird langsam und die 30000 Requests dauern mehr als 5 Mal so lange wie ohne PHP_FCGI_CHILDREN.

=> PHP_FCGI_CHILDREN aus deinem Starter-Script rausnehmen und bitte berichten, ob deine 500er weg sind, danke.

[theomega]

Oki, werde ich ausprobieren. Leider ist dein erster Tipp in die Hose gegangen, der Server hat durch ständiges spawnen sich selber weggeschossen, es waren halt auch keine Limits bezüglich prozesse oder ähnliches drin, der server war nurnoch per ping zu erreichen, ansonsten war er tot. Blöd nur das er sich jetzt auch nicht neustarten lässt.
Sehr dämlich, aber es bestätigt ja deine Theorie, wollen wir mal sehen ob du recht hast sobald mein lieber Hoste sich um den Server gekümmert hat.

[kase]

Args, muss mich vielmals entschuldigen.

Oftmals hat die Erhöhung der PHP_FCGI_CHILDREN geholfen, weil dann soo viele Prozesse da waren, dass sie die Last ohne Probleme abgefangen haben. Sprich das mod_fastcgi Modul hat keine weiteren Prozesse gespawnt, und alles lief sehr gut. Bei dir war es wohl dann so, dass selbst 20 Prozesse nicht für deine Last gereicht haben, fcgid hat weitere Prozesse (X*PHP_FCGI_CHILDREN) gespawnt und dein Amoklauf war noch schlimmer als mit deinen vorher eingestellten 10.

Ich habe leider mit stark frequentierten Systemen nicht mehr so die Erfahrung wie "damals", als ich das Apache2-phpfcgi-MOD_FASTCGI Howto geschrieben habe, weil ich zu diesem Zeitpunkt selbst mehrere sehr stark belastete PHP-Systeme administriert habe. Inzwischen sind es nur noch 2 kleine Server mit sehr wenigen Hits (1 Privat-Server + 1 Development-Server).

Ich hoffe, dass es ohne PHP_FCGI_CHILDREN ohne 500er läuft, dann hat dein (bzw besser mein *ggg*) ganzes Experimentieren wenigstens Erfolg gezeigt.

[theomega]

So, die Konfiguration ist geändert, mal sehen wie es sich auswirkt. Ich danke dir schonmal für deine Hilfe und du kannst dir sicher sein das ich mich nocheinmal melden.

Gruß
TO

[theomega]

Hy,
leider hat dein Tipp wenig gebracht:

1. Die "elternlosen" php-childs sind verschwunden, hier hat es also geholfen. Die Fork-Rate ist zurückgegangen und auch der RAM-Verbrauch. Also alles gut hier. NUR:

2. Der Internal Server Error bleibt. Ich habe es gerade nicht persönlich miterlebt aber es war wie immer: Niemand kam auf die Seite und nach ca. 4 MInuten ging wieder alles. Die Logdateien bleiben aussagelos wie immer:

Code: Select all

[Fri Jan 19 12:43:07 2007] [notice] mod_fcgid: process /srv/pagenstecher/html/seite/showtopic.php(31004) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 12:43:54 2007] [notice] mod_fcgid: process /srv/pagenstecher/html/seite/showtopic.php(27839) exit(normal exit), terminated by calling exit(), return code: 0
[Fri Jan 19 12:43:54 2007] [warn] mod_fcgid: cleanup zombie process 27839
[Fri Jan 19 12:44:12 2007] [notice] mod_fcgid: process /srv/pagenstecher/html/seite/showtopic.php(29822) exit(busy timeout), terminated by calling exit(), return code: 0
[Fri Jan 19 12:43:06 2007] [info] mod_fcgid: /srv/pagenstecher/html/seite/showtopic.php spawn score 33 >= 10, skip the spawn request

Code: Select all

[Fri Jan 19 12:40:10 2007] [debug] arch/unix/fcgid_proc_unix.c(512): (111)Connection refused: mod_fcgid: can't connect unix domain socket: /usr/lib/apache2/logs/fcgidsock/26063.17
[Fri Jan 19 12:41:03 2007] [debug] arch/unix/fcgid_proc_unix.c(512): (111)Connection refused: mod_fcgid: can't connect unix domain socket: /usr/lib/apache2/logs/fcgidsock/26063.26
[Fri Jan 19 12:42:19 2007] [warn] mod_fcgid: read data timeout in 60 seconds
[Fri Jan 19 12:42:19 2007] [error] [client 217.254.31.50] Premature end of script headers: search.php, referer: http://www.pagenstecher.de/topic121504,BMW---E36-Cabrio-325I.html

Wobei vor allem die Meldung mit der Spawn-Score extrem oft kommt. Die Anzahl der Childs ist aber extrem weit unten, noch ca. 10 Prozesse die laufen. Und die Geschwindigkeit der Seite ist wie immer hoch, also auch hier kein Problem.

Haste noch einen Tipp auf Lager? Irgendwie glaube ich nicht dass das erhöhen der SpawnScore etwas bringt, ich halte das für die Auswirkung von etwas und nicht für dasn Auslöser.

Was ich noch ausprobieren werde ist PHP auf Version 5.2 upzudaten, evtl liegs an der Version 5.1.6, es wurde laut changelog einiges am fastcgi-interface geändert, allerdings nichts was direkt auf mein Problem hindeutet

Dank allen!

Gruß
TO

[theomega]

So, kleines Statusupdate. Ich kann die Sache reproduzieren. Habe auf meinem Testserver genau die gleiche Software wie auf meinem Produktivserver, wenn ich nun von einem anderen Server (gleicher Hoster, also sehr schnell) ein Apache Benchmark dieser Art absetzte:

Code: Select all

ab2 -n 10000 -c 100 http://www.pageserv1.de/test.php

dann kommt es zu sehr komischen Effekten (wers selber ausprobieren will: Die URL geht, einfach den o.a. Befehl eingeben, der Server ist nur Test, macht mir nichts aus wenn der ein bischen bombadiert wird):

Die ersten 6000 requests gehen schnell, währenddessen kann man auch noch mit dem Browser auf die Seite zugreifen. Danach hängt die Seite komplett, dementsprechend lange dauert es bis das benchmark durchläuft. In der Logdateien kommen dann die alten fehler:

Code: Select all

[Fri Jan 19 16:25:38 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(22267) exit(communication error), terminated by calling exit(), return code: 0

Nachdem die Sache jetzt reproduzierbar ist fällt das testen evtl einfacher.

Wer hat ne Idee?

Danke
TO

[kase]

Erklär mal bitte ganz genau, wie du den Fehler reproduzierst.

Wichtig ist die exakte error.log vom Start bis zum Ende, vor allem die aller erste Error Meldung sollte evtl entscheidend sein.

Ich habe folgende PHP Datei bei mir auf dem Server erstellt:

Code: Select all

<?php

for ( $i=0; $i<=100; $i++ ) {
        $erg = $i*$i;
        echo $i."*".$i."=".$erg."<br>";
}

?>

Danach den Befehl angeworfen:

Code: Select all

ab -n 10000 -c 100 http://192.168.146.128/web/test.php

Ergebnis des Tests (ist ein relativ "schwacher" Server mit 256 MB RAM)
Apache 2.2.3, PHP 5.2.0

Code: Select all

Finished 10000 requests


Server Software:        Apache/2.2.3
Server Hostname:        192.168.146.128
Server Port:            80

Document Path:          /web/test.php
Document Length:        1351 bytes

Concurrency Level:      100
Time taken for tests:   11.901226 seconds
Complete requests:      10000
Failed requests:        0
Write errors:           0
Total transferred:      15240000 bytes
HTML transferred:       13510000 bytes
Requests per second:    840.25 [#/sec] (mean)
Time per request:       119.012 [ms] (mean)
Time per request:       1.190 [ms] (mean, across all concurrent requests)
Transfer rate:          1250.46 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.7      0       9
Processing:    75  116 565.0     85   11886
Waiting:       75  116 565.0     85   11886
Total:         75  116 565.3     85   11894

Percentage of the requests served within a certain time (ms)
  50%     85
  66%     86
  75%     87
  80%     87
  90%     88
  95%     93
  98%    175
  99%    213
 100%  11894 (longest request)

Das error.log während des Benchmarks ist dann folgendes:

Code: Select all

[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2809) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2810) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2811) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2824) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2828) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2834) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2840) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2841) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2842) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2847) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2852) started
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2860) started
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2865) started
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2869) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2874) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2879) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2883) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2887) started
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2896) started
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2901) started
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2906) started

Er hat also während des Benchmarks 21 php-fcgi Prozesse erstellt, ansonsten ist nichts weiteres passiert.

[Joe User]

Google ist leider auch nicht sehr viel schlauer:
http://permalink.gmane.org/gmane.comp.a ... eneral/197
http://www.fastcgi.com/archives/fastcgi ... 03626.html
http://www.google.com/search?hl=en&q=mo ... gle+Search

[theomega]

Hy,
oki, hier also die genaue Analyse:
die PHP-Datei ist ähnlich zu deiner, wobei die imho überhaupt keine Rolle spielt, ich wollte eine rpoduzieren die ein bischen inhalt ausgibt aber auf keinem modul o.ä. basiert. Ich habe jetzt folgendes gemacht:
1. den apache gestoppt.
2. die Logverzeichnisse komplett leergeräumt
3. den apache gestartet
4. auf einer anderen maschine:

Code: Select all

 ab2 -n 10000 -c 100 http://www.pageserv1.de/test.php

5. Das Ergebniss des ab:

Code: Select all

This is ApacheBench, Version 2.0.41-dev <$Revision: 1.121.2.12 $> apache-2.0
Copyright (c) 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Copyright (c) 2006 The Apache Software Foundation, http://www.apache.org/

Benchmarking www.pageserv1.de (be patient)
Completed 1000 requests
Completed 2000 requests
Completed 3000 requests
Completed 4000 requests
Completed 5000 requests
Completed 6000 requests
Completed 7000 requests
Completed 8000 requests
Completed 9000 requests
Finished 10000 requests


Server Software:        Apache
Server Hostname:        www.pageserv1.de
Server Port:            80

Document Path:          /test.php
Document Length:        1351 bytes

Concurrency Level:      100
Time taken for tests:   43.807096 seconds
Complete requests:      10000
Failed requests:        19
   (Connect: 0, Length: 19, Exceptions: 0)
Write errors:           0
Non-2xx responses:      19
Total transferred:      15016244 bytes
HTML transferred:       13495788 bytes
Requests per second:    228.27 [#/sec] (mean)
Time per request:       438.071 [ms] (mean)
Time per request:       4.381 [ms] (mean, across all concurrent requests)
Transfer rate:          334.74 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   3.1      0      76
Processing:     1  421 2732.1     54   31405
Waiting:        1  421 2732.1     53   31404
Total:          2  422 2732.1     54   31405

Percentage of the requests served within a certain time (ms)
  50%     54
  66%     59
  75%     67
  80%     76
  90%    143
  95%   1058
  98%   3002
  99%   7008
 100%  31405 (longest request)

Man beachte die 19 fehlgeschlagenen Requests

6. die Error-Log vom VHost:

Code: Select all

[Fri Jan 19 21:47:02 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:02 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:03 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:03 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:04 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:04 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:04 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:04 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:05 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:05 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:06 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:06 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:08 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:08 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:08 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:08 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:09 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:09 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:09 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:09 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:09 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:09 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:09 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:09 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:10 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:10 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:10 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:10 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:10 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:10 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:36 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:36 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:38 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:38 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:41 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:41 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:42 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:42 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php
[Fri Jan 19 21:47:45 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 21:47:45 2007] [error] [client 85.10.192.207] Premature end of script headers: test.php

7. Die Error-Log vom Apache:

Code: Select all

[Fri Jan 19 21:46:40 2007] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec2)
[Fri Jan 19 21:46:40 2007] [notice] Apache configured -- resuming normal operations
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25192) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25193) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25194) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25195) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25196) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25197) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25198) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25199) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25204) started
[Fri Jan 19 21:47:01 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:02 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25205) started
[Fri Jan 19 21:47:02 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:02 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25206) started
[Fri Jan 19 21:47:02 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:03 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25207) started
[Fri Jan 19 21:47:03 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:03 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25220) started
[Fri Jan 19 21:47:04 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:04 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25291) started
[Fri Jan 19 21:47:05 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:05 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25293) started
[Fri Jan 19 21:47:05 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25194) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:05 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25195) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:05 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25193) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:05 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25192) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:09 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25293) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:09 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25291) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:09 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25199) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:09 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25197) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:09 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25196) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:13 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25220) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:13 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25207) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:13 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25206) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:13 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25204) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:13 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25198) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:13 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25205) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:36 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:36 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25303) started
[Fri Jan 19 21:47:37 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:37 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25304) started
[Fri Jan 19 21:47:37 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25303) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:40 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:40 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25305) started
[Fri Jan 19 21:47:41 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:41 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25306) started
[Fri Jan 19 21:47:41 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25304) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:44 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:44 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25307) started
[Fri Jan 19 21:47:45 2007] [notice] mod_fcgid: call /srv/pageserv1/html/test.php with wrapper /srv/php-fcgi-scripts/pageserv1/php-fcgi-starter
[Fri Jan 19 21:47:45 2007] [notice] mod_fcgid: server /srv/pageserv1/html/test.php(25308) started
[Fri Jan 19 21:47:45 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25306) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:45 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25305) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 21:47:49 2007] [notice] mod_fcgid: process /srv/pageserv1/html/test.php(25307) exit(communication error), terminated by calling exit(), return code: 0

Alle Log-dateien sind komplett also wirklich von anfang bis ende. Hilft das jetzt weiter? ich habe schon bereits alle mod_fastcgid Einstellungen ausgeschaltet (Standart) und trotzdem geht es nicht besser oder schlecht. Die Anzahl der Childs ist im Starter nicht gesetzt. so das die Verwaltung beim mod_fcgid bleiben sollte. Kannst du evtl mal deinen Starter und deine Config posten, dann probier ich es mir deiner aus.
Mir geht es bei dem ab nicht um die antwortzeiten, sondern das es bei 19 requests zu einem 500erter kommt und das ewig dauert. Deshalb sollten eigentlich auch RAM usw zweitranging sein, wobei der Testserver (also da wo der apache läuft) 2GB Ram und einen 3GHz CPU hat, dass sollte also wirklich nicht das problem sein.

Haste mir evtl noch einen Tipp? Oder wie gesagt zumindest deine config, evtl gehts ja mit der!

@JU: Danke, aber ich hatte natürlich bereits vorher bei Google gesucht. Außerdem habe ich einen Request an die Mailingliste von mod_fcgid geschickt, aber dort scheint man sich nicht um solche Probleme kümmern zu wollen.

Gruß
TO

[kase]

Also ich habe nochmal etwas rumgespielt mit deiner Config.

Vor allem die Option

Code: Select all

MaxRequestsPerProcess 440

macht bei mir starke Probleme.

[SPOILER]
Die Option macht übrigens nichts anderes als

Code: Select all

PHP_FCGI_MAX_REQUESTS=440
export PHP_FCGI_MAX_REQUESTS

im PHP_FCGI_STARTER zu setzen, also

MaxRequestsPerProcess 440 in der fcgid.conf ist genau das gleiche wie PHP_FCGI_MAX_REQUESTS=440 export PHP_FCGI_MAX_REQUESTS im php-fcgi-starter-script.
[/SPOILER]

Ohne die MaxProcess-Option sind während des Benchmarks nur "info" Meldungen von wegen "neuer Server gestartet" (siehe Post drüber).

Mit dieser Option allerdings ist mein Error-Log voll mit diesen Meldungen (unzählige Zeilen, bin zu faul zum Zählen)

Code: Select all

[Fri Jan 19 20:38:55 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 20:38:55 2007] [error] [client 192.168.146.128] Premature end of script headers: test.php
[Fri Jan 19 20:38:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 20:38:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(5511) started
[Fri Jan 19 20:38:56 2007] [notice] mod_fcgid: process /var/www/vhosts/legendz.lan/web/test.php(5510) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 20:38:56 2007] [debug] arch/unix/fcgid_proc_unix.c(512): (111)Connection refused: mod_fcgid: can't connect unix domain socket: /var/lib/apache2/fcgid/sock/5319.16
[Fri Jan 19 20:38:59 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 20:38:59 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(5512) started
[Fri Jan 19 20:38:59 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 20:38:59 2007] [error] [client 192.168.146.128] Premature end of script headers: test.php
[Fri Jan 19 20:39:00 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 20:39:00 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(5513) started
[Fri Jan 19 20:39:00 2007] [notice] mod_fcgid: process /var/www/vhosts/legendz.lan/web/test.php(5512) exit(communication error), terminated by calling exit(), return code: 0
[Fri Jan 19 20:39:00 2007] [notice] mod_fcgid: process /var/www/vhosts/legendz.lan/web/test.php(5511) exit(server exited), terminated by calling exit(), return code: 0
[Fri Jan 19 20:39:00 2007] [warn] (104)Connection reset by peer: mod_fcgid: read data from fastcgi server error.
[Fri Jan 19 20:39:00 2007] [error] [client 192.168.146.128] Premature end of script headers: test.php
[Fri Jan 19 20:39:04 2007] [notice] mod_fcgid: process /var/www/vhosts/legendz.lan/web/test.php(5513) exit(communication error), terminated by calling exit(), return code: 0
...
...
...

Die Error Meldungen sehen deinen auf den ersten Blick sehr ähnlich. Der Test ist ebenfalls wesentlich langsamer und hängt teilweise.

=> TODO

1.
Die Zeile
MaxRequestsPerProcess 440
aus der fcgid.conf rausnehmen

2.
Die Zeilen
PHP_FCGI_MAX_REQUESTS=5000
export PHP_FCGI_MAX_REQUESTS
in dein php-fcgi-starter-script mit aufnehmen, wobei der Wert >>>>> 5000 (mindestens 5000) zu wählen ist. Bei einem Wert 5000 und einem "ab" mit 50000 Requests habe ich dann zwar immer noch ein paar ganz wenige Fehlermeldungen von wegen Cant read socket, allerdings folgt darauf nicht die Meldung "Communication Error" sondern "Server exit", und der Prozess wird einfach neu gestaret.

Ich denke, wir sind der Lösung deines Problems sehr nahe, bitte um Feedback :) :)

[theomega]

Hey,
sieht sehr gut aus, habe den Fehler wegbekommen. Weshalb ich diese Einträge drin hatte: Es geht das Grücht um (in diversen Mailinglisten) das der PHP nach ungefähr 500 Requests manchmal in eine Racecondition läuft und hängen bleibt. Deshalb soll man ihn vorher beenden lassen. Deshalb die Zahl.
Aber es geht ja wie es scheint auch ohne. Brauch ich die Zahl in meinem Starter überhaupt? ich habe es jetzt auf 10000 gestellt und keine Probleme gehabt, die ausgabe ist die gleiche wie deine.

Ich änder das gleich mal auf dem produktivserver, mal sehen ob es dort auch was hilft, sieht auf jeden fall besser aus als sonst.

Ich dank dir auf jeden fall schonmal ganz arg!

Gruß
TO

[kase]

Ja, ich würde schon nach einer sehr hohen Zahl an Requests den PHP Prozess neu starten lassen, da man so Speicherproblemen (memory leaks oder ähnlich) vorbeugt, indem einfach alle X Requests der Prozess neu startet.

Die Zahl 440 war aber viel zu wenig, im Endeffekt ist es eigentlich auch logisch.

Mit dem Apache Benchmark hast du 100 konkurrente User, im Mittel hat bei mir jeder Request 1,4 ms gedauert.

Wenn du das jetzt mal auf 440 Requests hochrechnest, dann vergeht nur eine sehr sehr kurze Zeit, bis das Limit schon erreicht ist. Dass da fcgid Probleme mit dem Prozess-Management bekommt, ist da nicht so verwunderlich.

Und von diesem Gerücht mit den 500 Requests habe ich auch schon gehört, hatte aber noch nie Probleme damit, und deswegen habe ich mom als Limit 5000 drin, habe aber auch schon überlegt, den Wert nochmal zu verdoppeln oder sogar zu verdreifachen/vervierfachen, gerade nach den Überlegungen/Problemen aus diesem Thread.

Achso, und melde dich bitte nochmal bezüglich deines Produktivservers, ob es dort auch geholfen hat, thx.

[theomega]

Hy,
es tut mir wirklich leid, aber es hat auf dem Produktivserver nicht geholfen. Gerade eben sind wieder 500erter aufgetreten. Allerdings steht in den Log-Files was anderes:
der apache-error-log sagt extrem oft:

Code: Select all

[Sun Jan 21 13:40:45 2007] [info] mod_fcgid: /srv/pagenstecher/html/seite/showtopic.php spawn score 10 >= 10, skip the spawn request

und der vhost-error-log sagt:

Code: Select all

[Sun Jan 21 13:40:47 2007] [warn] mod_fcgid: can't apply process slot for /srv/pagenstecher/html/seite/showtopic.php

auch das extrem oft.

Es treten also keine Communicationerrors mehr auf. Soll ich einfach mal die Spawn-Score anheben oder geht das wieder nach hinten los. Wenn ja, auf welchen Wert würdet ihr mir empfehlen?

danke
TO

[Joe User]

Die Fehlermeldungen besagen beidedas Gleiche und sollten dementsprechend nahezu gleichzeitig/oft auftreten.

Erhöhe die Spawn-Score vorsichtig in 5er-Schritten und behalte jeweils das System zur Rush-Hour im Auge.

Viel Glück und berichte bitte weiter, zudem interessiert mich die endgültige Lösung/Config ;)

[kase]

EDIT: ACHTUNG, weil es Joe auch gerade geschrieben hat, NICHT die SpawnScore erhöhen, sondern das SpawnScoreUpLimit, UNBEDINGT die Doc dazu lesen !!!

Wie viele php-fcgi Prozesse hast du denn inzwischen?

Hast du die PHP_FCGI_CHILDREN Variable auch auf deinem Produktiv-Server rausgeworfen, nicht, dass der unnötig viele Prozesse spawnt.

Wenn du sicher sein kannst, dass pro Spawn defintiv nur 1 Prozess erzeugt wird, solltest du das SpawnScoreUpLimit erhöhen können.

Was genau das SpawnScoreUpLimit macht, ist sogar am Apache Benchmark recht einfach zu sehen.

Folgenden Code habe ich oben schon mal gepostet, du siehst hier genau, wie das SpawnScoreUpLimit von 10 greift:

Code: Select all

[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2809) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2810) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2811) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2824) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2828) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2834) started
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:55 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2840) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2841) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2842) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2847) started
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:56 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2852) started

===> Hier sind 10 Prozesse erzeugt, er wartet 3 Sekunden, bis er weitere 10 erzeugt.  <===


[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2860) started
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2865) started
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:31:59 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2869) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2874) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2879) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2883) started
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:03 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2887) started

===> Hier wieder 10, danach 3 Sek Delay <===

[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2896) started
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2901) started
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: call /var/www/vhosts/legendz.lan/web/test.php with wrapper /var/www/vhosts/legendz.lan/fastcgi/php-fcgi
[Fri Jan 19 19:32:06 2007] [notice] mod_fcgid: server /var/www/vhosts/legendz.lan/web/test.php(2906) started

Also wichtig ist, dass du nicht die SpawnScore erhöhst, sondern das SpawnScoreUpLimit (siehe DOC). SpawnScore ist der Wert, der draufaddiert wird, bei einem Prozess-Spawn, bis SpawnScoreUpLimit erreicht wurde.

Was ich nicht ganz verstehe ist, warum er bei dir diese Fehler ausspuckt, bei mir hingegen einfach 3 Sek wartet und dann weiter spawnt.

Das wiederrum kannst du nur rausfinden, wenn du deine php-fcgi Prozesse (vor allem die Anzahl) genau beobachtest. Eventuell schiessen deine php-fcgi Prozesse während solch eines Fehlers extrem in die Höhe, warum auch immer.

Schützen kannst du dich per MaxProcessCount, eventuell mit dem Wert etwas heruntergehen, default ist 1000.

SpawnScoreUpLimit würde ich auch erstmal nur max verdoppeln, sicher ist sicher.

Schreib dir doch mal ein Cronjob, der jede Minute die Anzahl der Prozesse zählt (ps aux | grep PHP_BIN_NAME | wc -l), vielleicht erkennt man daraus etwas.

Eine ganz blöde Idee habe ich zudem noch:

Vielleicht passiert solch ein 500er genau nach einer Stunde immer??? Dort müsstest du mal die Zeiten im Log vergleichen. Denn:

Code: Select all

ProcessLifeTime n (3600 seconds)

A fastcgi application will be terminated if lifetime expired, even no error is detected.

Eventuell killen sich nach einer Stunde sämtliche php-fcgi Prozesse, und das fcgid Modul kommt dann nicht mit dem Nachspawnen hinter her. Eine Erhöhung dieses Wertes halte ich aber nicht für sehr sinnvoll, da es dir dann nicht nach einer sondern nach 2 Stunden passiert. Wobei ich jetzt nicht genau weiß, inwiefern dieser Wert mit PHP_MAX_REQUESTS kombiniert wird.

Eine Garantie, dass du dir den Server nicht nochmal abschiesst, kann ich dir natürlich nicht geben, aber ohne PHP_FCGI_CHILDEN solltest du einigermaßen auf der sicheren Seite sein. (Zur Not ssh Session auf lassen, dann kannst du sofort reagieren. Falls dein Provider eine externe Firewall anbietet, viele machen das inzwischen, kannst du wenns zu schlimm wird einfach kurz Port 80 sperren.)

[theomega]

Hy,
danke für eure Hilfe:
1. ich habe die SpawnScoreUpLimit auf 15 gesetzt
2. ich bin sicher das nirgends mehr der FCGI_CHILDREN gesetzt wird
3. Es tritt wesentlich seltener als einmal pro Stunde auf, eher einmal pro Tag
4. Ein kleines Script läuft und loggt jede Minute die anzahl der Prozesse.

Welchen Wert für SpawnScoreUpLimit empfiehlst du oder in welchem Schritten soll ich nach oben gehen?

Danke
TO

[kase]

Also, eigentlich wollte ich heute fürs Studium lernen (letztes Schein-Semester), aber es lässt mir einfach keine Ruhe, deswegen sitze ich jetzt seit 13:45 an mod_fcgid rum und probiere alles mögliche aus.

Damit ich auch ordentlich testen kann, habe ich einfach mal den concurrency-Level nochmal verdoppelt, nämlich auf 200. Die Gesamt-Requests habe ich auf 100.000 erhöht, damits auch über längere Zeit was zu tun gibt.

Und das überraschende Resultat:

Egal was ich eingestellt habe, und ich habe bestimmt 200-300 unterschiedliche Konfigurationen getestet (geringes SpawnScoreUpLimit, hohes SpawnScoreUpLimit, niedrige ProcessLifeTime, hohe ProcessLifeTime, MaxProcessCount verändert, hohes bzw niedriges IPCConnectTimeout, hohe bzw niedrige MaxRequestsPerProcess, mal mit fcgid.conf gesetzt, mal mit dem php-fcgi-starter gesetzt, und das natürlich in den unterschiedlichsten Zusammenstellungen), das Ergebnis war:

Es waren IMMER mindestens 25 Requests (oft deutlich mehr) fehlerhaft, sprich 500er, kein einziger AB-Durchlauf hat keine Warnings im error.log produziert, wobei die Fehler teilweise extremst unterschiedlich waren, sowohl in den Meldungen als auch in der "Menge".

Also habe ich gedacht, das kanns ja nicht sein, und habe einen komplett anderen Ansatz probiert. (Die Idee ist mir während des Testens gekommen)

Man setze einfach die maximale Anzahl der php-fcgi Prozesse auf 1 pro vHost, dies machen wir mit

Code: Select all

DefaultMaxClassProcessCount n (100)

The maximum number of fastcgi application instances allowed to run for any one fastcgi application. 

DefaultMinClassProcessCount n (3)

The minimum number of fastcgi application instances for any one fastcgi application. 

also DefaultMaxClassProcessCount 1 und DefaultMinClassProcessCount 1.

Nun haben wir mod_fcgid quasi die Kontrolle über das Prozessmanagement entzogen, es spawnt zu Beginn einen Prozess und ist dann mehr oder weniger machtlos.

Die Prozesssteuerung überlassen wir php, indem wir in unserem php-fcgi-starter die PHP_FCGI_CHILDREN setzen.

=>

Das Ergebnis war sehr positiv, keine 500er mehr, keinen einzigen fehlgeschlagenen Request, und das bei 100.000 Requests, 200er concurreny und fast 60er Load.

Natürlich hatte auch diese Lösung Nachteile:

1. Im Error.log das Apache findet sich relativ häufig der Eintrag:

Code: Select all

[Sun Jan 21 15:52:44 2007] [notice] mod_fcgid: too much /var/www/vhosts/web/test.php process(current:1, max:1), skip the spawn request

was aber außer Datenmüll nichts weiter macht, fcgid denkt einfach, dass 1 Prozess für 200 gleichzeitige User nicht reicht, kann aber nicht mehr spawnen, wegen dem Limits. Natürlich existiert auch nicht nur 1 Prozess, sondern PHP_FCGI_CHILDREN viele.

2. Theoretisch könnte es doch einmal passieren, dass fcgid den Haupt-php-fcgi-Prozess killt, warum auch immer. Da dieser leider der Parent ist, und alle anderen Childs von ihm abhängen, hat man dann PHP_FCGI_CHILDREN Prozesse im INIT hängen, die elternlos sind und nichts mehr machen außer Speicher verbrauchen. mod_fcgid wird den Parent Prozess natürlich neu starten, und php spawnt auch brav wieder seine PHP_FCGI_CHILDREN. Der Server-Betrieb sollte also dadurch nicht beeinträchtigt werden.

Achtung: 2. passiert zB wenn man den Apache beendet. Man muss also den Apache stoppen, alle PHP_FCGI_CHILDREN killen (killall php5-cgi bei Debian) und den Apache wieder starten. Eventuell könnte man auch ein Script schreiben, was einfach alle php5-cgi Prozesse killt, die als Parent den Init haben, und das hängt man dann in den php-fcgi starter rein. Somit hätte man 2. komplett gelöst.

Hier meine Konfiguration, die dann wirklich absolut 500er-los war:

fcgid.conf:

Code: Select all

<IfModule mod_fcgid.c>
  AddHandler fcgid-script .fcgi
  SocketPath /var/lib/apache2/fcgid/sock
  # MaxProcessCount muss groesser sein als es vHosts mit php-fcgi support gibt
  MaxProcessCount 10
  # Fuer jeden vHost nur ein einziges php-fcgi binary starten,
  # das Prozessmanagement uebernimmt php mittels PHP_FCGI_CHILDREN
  DefaultMaxClassProcessCount 1
  DefaultMinClassProcessCount 1
  # fcgid soll keine Prozesse beenden
  MaxRequestsPerProcess -1
  ProcessLifeTime -1
</IfModule>

php-fcgi-starter

Code: Select all

#!/bin/sh
# Pfad zur php.ini, ohne / am Ende.
PHPRC="/var/www/fastcgi/timo"
export PHPRC
# Maximale Requests pro php-Prozess, verhindert immer
# groesser werdende php-binarys zB durch memory leaks.
# Nicht zu niedrig waehlen, da sonst bei hoher Load
# die Binarys zu oft neu gestartet werden muessen. (>=5000)
PHP_FCGI_MAX_REQUESTS=5000
export PHP_FCGI_MAX_REQUESTS
# Anzahl an php-fcgi-children (Prozesse), mindestens 2, maximal 100.
# Ein guter Wert (gemessen mit AB (Apache Benchmarking Tool) ist
# "Anzahl gleichzeitiger PHP Zugriffe (concurrency) geteilt durch 4"
PHP_FCGI_CHILDREN=50
export PHP_FCGI_CHILDREN
# IP Adresse, von der connections akzeptiert werden, normalerweise nur localhost
FCGI_WEB_SERVER_ADDRS="127.0.0.1"
export FCGI_WEB_SERVER_ADDRS
exec /usr/bin/php5-cgi

PHP_FCGI_CHILDREN=50 ist natürlich ziemlich viel, habe ich nur so hoch gesetzt wegen dem AB, ich denke, man sollte mit einem wesentlich kleineren Wert anfangen.