[lamp] Beroerde performance met php5

[Martijn02]

Ik ben bezig een verhuizing van onze website voor te bereiden naar een nieuwe server. Heb van de gelegenheid gebruik gemaakt om meteen even te testen met de nieuwste mysql en php versies.

Het gaat om de site www.gfxartist.com. Ben begonnen met een schone redhat installatie, heb de standaard httpd/php/mysql er af gegooid, en daar zelf een nieuwe apache (2.2.4), php (4.4.7) met APC (3.0.14) en mysql (5.0.37) op gezet.

Na wat klooien heb ik de site draaien, en geeft http_load een gemiddelde van 24 fetches/sec. op zich niet om over naar huis te schijven, maar beter dan de oude situatie.

[root@chifu src]# http_load -parallel 5 -fetches 1000 homepage.txt
1000 fetches, 5 max parallel, 8.14169e+07 bytes, in 41.2557 seconds
81416.9 mean bytes/connection
24.2391 fetches/sec, 1.97347e+06 bytes/sec
msecs/connect: 0.110745 mean, 7.061 max, 0.027 min
msecs/first-response: 189.295 mean, 460.249 max, 131.803 min

Omdat ik benieuwd was hoe de site met php5 zou werken heb ik ook php even geinstalleerd. Hij is geconfigured met dezelfde flags als php4, ook voor php5 heb ik APC geinstalleerd.

Na de httpd.conf file te hebben omgegooid, en de server herstart te hebben draait de site onder php5. w00t! Mooi, ff kijken hoe dat performd... http_load... duurtlang!.... zucht... steun...

[root@chifu src]# http_load -parallel 5 -fetches 100 homepage.txt
100 fetches, 5 max parallel, 8.1716e+06 bytes, in 103.765 seconds
81716 mean bytes/connection
0.963717 fetches/sec, 78751.1 bytes/sec
msecs/connect: 0.10028 mean, 0.152 max, 0.027 min
msecs/first-response: 165.154 mean, 248.71 max, 143.239 min

Jamaar... daar worden we niet vrolijk van! Tijdens de loadtest ontstaat er nauwelijks load, cpu is steeds > 90% idle, en als ik in de accesslog kijk krijg ik echt vreemde resultaten. (let even op de tijden)

74.52.35.242 - - [06/May/2007:19:07:40 +0200] "GET / HTTP/1.0" 200 81481
74.52.35.242 - - [06/May/2007:19:07:40 +0200] "GET / HTTP/1.0" 200 81350
74.52.35.242 - - [06/May/2007:19:07:40 +0200] "GET / HTTP/1.0" 200 81483
74.52.35.242 - - [06/May/2007:19:07:40 +0200] "GET / HTTP/1.0" 200 81340
74.52.35.242 - - [06/May/2007:19:07:40 +0200] "GET / HTTP/1.0" 200 81470
74.52.35.242 - - [06/May/2007:19:07:45 +0200] "GET / HTTP/1.0" 200 81396
74.52.35.242 - - [06/May/2007:19:07:45 +0200] "GET / HTTP/1.0" 200 81449
74.52.35.242 - - [06/May/2007:19:07:45 +0200] "GET / HTTP/1.0" 200 81410
74.52.35.242 - - [06/May/2007:19:07:45 +0200] "GET / HTTP/1.0" 200 81522
74.52.35.242 - - [06/May/2007:19:07:45 +0200] "GET / HTTP/1.0" 200 81367
74.52.35.242 - - [06/May/2007:19:07:50 +0200] "GET / HTTP/1.0" 200 81356
74.52.35.242 - - [06/May/2007:19:07:50 +0200] "GET / HTTP/1.0" 200 81436
74.52.35.242 - - [06/May/2007:19:07:50 +0200] "GET / HTTP/1.0" 200 81413
74.52.35.242 - - [06/May/2007:19:07:50 +0200] "GET / HTTP/1.0" 200 81457
74.52.35.242 - - [06/May/2007:19:07:50 +0200] "GET / HTTP/1.0" 200 81496
74.52.35.242 - - [06/May/2007:19:07:55 +0200] "GET / HTTP/1.0" 200 81359
74.52.35.242 - - [06/May/2007:19:07:55 +0200] "GET / HTTP/1.0" 200 81509
74.52.35.242 - - [06/May/2007:19:07:55 +0200] "GET / HTTP/1.0" 200 81364
74.52.35.242 - - [06/May/2007:19:07:55 +0200] "GET / HTTP/1.0" 200 81457
74.52.35.242 - - [06/May/2007:19:07:55 +0200] "GET / HTTP/1.0" 200 81434
74.52.35.242 - - [06/May/2007:19:08:00 +0200] "GET / HTTP/1.0" 200 81402
74.52.35.242 - - [06/May/2007:19:08:00 +0200] "GET / HTTP/1.0" 200 81346
74.52.35.242 - - [06/May/2007:19:08:00 +0200] "GET / HTTP/1.0" 200 81441
74.52.35.242 - - [06/May/2007:19:08:00 +0200] "GET / HTTP/1.0" 200 81404
74.52.35.242 - - [06/May/2007:19:08:00 +0200] "GET / HTTP/1.0" 200 81389

Voor de zekerheid php4 nog even teruggezet, en whopaa hij loopt weer als een trein.. maar php5 is wel uberberoerd zo...

Het is geen drama, php5 is niet nodig ofzo, ik had gewoon gehoopt dat het iets sneller zou draaien, Ik kan me ook niet voorstellen dat php5 25 keer langzamer draait dan versie 4, dus ik zal ongetwijfeld iets over het hoofd gezien hebben... Ik staar er nu al een uurtje naar, ben bezig geweest met valgrind, maar krijg het niet werkend, Wie kan me verder helpen???

[Verwijderd]

Bij benchmarks van onze code kwam naar voren dat het opvragen van alle constanten vreselijk veel tijd kostte, omdat er kennelijk een hoop nieuwe bij waren. Niet dat dat je probleem is, maar je kunt waarschijnlijk de bottleneck vinden door afzonderlijke delen te gaan benchmarken.

[Verwijderd]

Ik mag hopen dat je PHP5 niet als CLI draait ?

[Martijn02]

Verwijderd schreef op zondag 06 mei 2007 @ 19:28:
Ik mag hopen dat je PHP5 niet als CLI draait ?

Neeh, Hij hangt netjes als DSO in apache... (net als php4, ik wissel alleen het hekje)

LoadModule php4_module        modules/libphp4.so
#LoadModule php5_module        modules/libphp5.so

[ Voor 27% gewijzigd door Martijn02 op 06-05-2007 19:40 ]

[Martijn02]

Ok... benchmark blijft verbazende resultaten geven...

Deze php:

PHP:

<?php
header ("HTTP/1.1 200 OK");
phpinfo();
?>

Geeft:

[root@chifu ~]# http_load -parallel 5 -fetches 100 phpinfo.txt
100 fetches, 5 max parallel, 4.4801e+06 bytes, in 100.064 seconds
44801 mean bytes/connection
0.999358 fetches/sec, 44772.2 bytes/sec
msecs/connect: 0.07998 mean, 1.43 max, 0.026 min
msecs/first-response: 1.03399 mean, 2.137 max, 0.435 min
HTTP response codes:
  code 200 -- 100

In vergelijking tot:

PHP:

<?php
//header ("HTTP/1.1 200 OK");
phpinfo();
?>

[root@chifu ~]# http_load -parallel 5 -fetches 100 phpinfo.txt
100 fetches, 5 max parallel, 4.4606e+06 bytes, in 0.064775 seconds
44606 mean bytes/connection
1543.81 fetches/sec, 6.8863e+07 bytes/sec
msecs/connect: 0.30365 mean, 2.695 max, 0.025 min
msecs/first-response: 1.83766 mean, 4.36 max, 0.426 min
HTTP response codes:
  code 200 -- 100

FTW!??!?

/edit:

Nouja; heb de headers overbodig gemaakt door de manier van aanroepen te veranderen naar een mod_rewrite in plaats van de 404_error handler die het vroeger was. PHP5 loopt nu best lekker...

[ Voor 11% gewijzigd door Martijn02 op 06-05-2007 22:13 ]

[Kalentum]

Resulten met PHP5 en een echte webapp op localhost (Gregarius)

code:

 ./http_load -parallel 5 -fetches 100 urls
100 fetches, 5 max parallel, 4.2993e+06 bytes, in 28.7468 seconds
42993 mean bytes/connection
3.47865 fetches/sec, 149557 bytes/sec
msecs/connect: 0.14752 mean, 0.344 max, 0.034 min
msecs/first-response: 1398.35 mean, 16487.4 max, 357.08 min

Maar met alleen phpinfo() krijg ik ook treurige resultaten. Vreemd. Misschien dat de internals zodanig zijn veranderd dat het oplepelen van config informatie zo lastig is.

[smesjz]

Welke MPM gebruik je? Worker? Prefork, Event?

Die extra header ("HTTP/1.1 200 OK"); is nergens voor nodig. Deze wordt al geplaatst door de server (of PHP).

Ik merk niks van een mindere performance van PHP5. Maar een goede vergelijking is het draaien van de Zend/bench.php vanaf de CLI.
Als die ongeveer hetzelfde geven kan je verder testen met Apache/PHP4 en Apache/PHP5.

[Martijn02]

smesjz schreef op zondag 06 mei 2007 @ 22:43:
Welke MPM gebruik je? Worker? Prefork, Event?

Die extra header ("HTTP/1.1 200 OK"); is nergens voor nodig. Deze wordt al geplaatst door de server (of PHP).

Ik merk niks van een mindere performance van PHP5. Maar een goede vergelijking is het draaien van de Zend/bench.php vanaf de CLI.
Als die ongeveer hetzelfde geven kan je verder testen met Apache/PHP4 en Apache/PHP5.

Gebruik de prefork MPM. (Eigenlijk niet bewust voor gekozen, is standaard)

Die header was vroeger wel nodig, omdat de applicatie stamt uit de tijd dat ik nog niet van mod_rewrite gehoord had (misschien bestond het ook nog wel niet) toen zetten we de index.php als errorDocument in apache, en moest de index.php dus ze 404 header in apache overschrijven, en dat gaat met de beschreven header.

Heb inmiddels de applicatie herschreven zodat hij gewoon met mod-rewrite werkt, en kon de header worden verwijderd. De site loopt nu goed, en haalt zo'n 26 a 27 requests per second. (en da's toch 2 a 3 requests meer dan met php4)

Edit: zie net dat mod_rewrite uit 1996 stamt, dus het is ouder dan de website

[ Voor 3% gewijzigd door Martijn02 op 10-05-2007 12:21 ]

[deadinspace]

Met zulke lage resultaten bij lage CPU load denk ik niet aan een echt performance probleem, maar meer aan een timeout-achtig iets, zoals bv het falen van een reverse resolve.

Martijn02 schreef op zondag 06 mei 2007 @ 20:10:
Ok... benchmark blijft verbazende resultaten geven...

PHP:

<?php
header ("HTTP/1.1 200 OK");
phpinfo();
?>

± 1 fetch/sec

PHP:

<?php
//header ("HTTP/1.1 200 OK");
phpinfo();
?>

± 1500 fetches/sec

Hoeveel gelijktijdige connecties sta je maximaal toe in apaches config? Helpt het als je dat aantal bijvoorbeeld verdubbeld?

Ik weet niks zeker, maar ik kan me zomaar voorstellen dat je door die HTTP1/1 response impliciet een keepalive aanzet, waardoor de connectie bijvoorbeeld 30 seconden open blijft. Als je dan maximaal 30 connecties toestaat, dan krijg je inderdaad vrij precies 1 fetch/sec.