Comment déboguer les délais d'attente Apache?

J'exécute une application Web PHP sur un serveur Apache 2.2 (Ubuntu Server 10.04, 8x2GHz, 12Gb RAM) en utilisant prefork. Chaque jour, Apache reçoit environ 100 000 à 200 000 demandes, dont environ 100 à 200 atteignent le délai d'expiration (donc environ une personne sur mille), à ​​peu près toutes les autres demandes sont traitées bien en dessous du délai d'expiration.

Que puis-je faire pour savoir pourquoi cela se produit? Ou est-il normal que certaines petites parties de toutes les demandes expirent?

Voici ce que j'ai fait jusqu'à présent:

Comme on peut le voir, il y a très peu de demandes entre le délai d'expiration et une demande plus raisonnable. Actuellement, le délai d'expiration est fixé à 50 secondes, auparavant il était fixé à 300 et c'était toujours la même situation avec quelques délais d'attente, puis un énorme écart vers les autres demandes.

Toutes les demandes qui expirent sont des AJAXdemandes, mais la grande majorité d'entre elles le sont, alors c'est peut-être plus une coïncidence. Le code de retour Apache est 200, mais le délai d'expiration est clairement atteint. Ils proviennent d'une large gamme d'adresses IP différentes.

J'ai examiné les demandes qui arrivent à expiration et il n'y a rien de spécial à leur sujet, si je fais les mêmes demandes qu'elles passent en beaucoup moins d'une seconde.

J'ai essayé de regarder les différentes ressources pour voir si je peux trouver la cause mais pas de chance. Il y a toujours beaucoup de mémoire disponible (le minimum est d'environ 3 Go), la charge peut parfois atteindre 1,4 et l'utilisation du processeur à 40%, mais de nombreux délais d'expiration se produisent lorsque la charge et l'utilisation du processeur sont faibles. L'écriture / lecture sur disque est à peu près constante pendant la journée. Il n'y a aucune entrée dans le journal des requêtes lentes MySQL (configuré pour enregistrer quoi que ce soit au-dessus de 1 seconde), aucune demande n'utilise autant d'écritures / lectures de base de données.

Le bleu correspond à l'utilisation du processeur, qui culmine à 40%, le marron à la charge avec un pic à 1,4. Nous pouvons donc voir que nous obtenons des délais d'attente même avec une faible utilisation / charge du processeur (les pics de dix secondes correspondent bien à l'utilisation du processeur, mais c'est un autre problème, j'ai plus d'espoir de découvrir ce qui pourrait en être la cause).

Il n'y a aucune erreur dans le journal des erreurs Apache et je ne l'ai pas vu atteindre plus de 200 processus Apache actifs.

Paramètres du serveur:

Timeout 50 
KeepAlive On
MaxKeepAliveRequests 100
KeepAliveTimeout 2

<IfModule mpm_prefork_module>
    ServerLimit     350
    StartServers        20
    MinSpareServers     75
    MaxSpareServers     150
    MaxClients          320
    MaxRequestsPerChild 5000
</IfModule>

Mise à jour:

J'ai mis à jour vers Ubuntu 12.04.1, juste au cas où, aucun changement. J'ai ajouté mod_reqtimeout avec les paramètres:

RequestReadTimeout header=20-40,minrate=500
RequestReadTimeout body=10,minrate=500

Maintenant, presque tous les délais d'expiration se produisent à 10 secondes, un ou deux à 20 secondes. Je suppose que cela signifie que la plupart du temps, il reçoit le corps de la demande qui est problématique à recevoir? Le corps de la demande ne doit jamais être supérieur à quelques centaines d'octets. J'ai surveillé le trafic réseau sur une base par 1 seconde et il ne dépasse jamais 1 Mbit / s et je ne vois aucun rxerrs ou rxdorps, étant donné que le serveur est sur une ligne à 1 Gbit / s, il ne ressemble pas le HopelessN00b a posté. Serait-ce juste un cas de mauvaises connexions utilisateur?

Pour les pics toutes les heures (ils semblent dériver un peu, dans les graphiques ci-dessus, ils sont à 33 minutes après l'heure, maintenant ils sont à 12 minutes), j'ai essayé de voir s'il y avait quelque chose qui fonctionnait périodiquement ( crons etc) mais n'a rien trouvé. Le garbage collection PHP fonctionne deux fois par heure, mais pas au moment des pics, j'ai quand même essayé de le désactiver mais cela ne fait aucune différence.

J'ai utilisé dstat avec --top-cpu et top pour regarder les processus au moment des pics et tout ce qui apparaît est qu'apache travaille dur pendant quelques secondes mais aucun autre processus n'utilise un processeur important.

J'ai fait un zoom sur les graphiques des pointes:

Pour moi, il semble qu'Apache s'arrête pendant quelques secondes, puis travaille dur pour traiter les demandes reçues pendant l'arrêt. Qu'est-ce qui pourrait provoquer un tel arrêt ou est-ce que je l'interprète mal?

La première chose que je note, en regardant votre premier graphique, il semble y avoir un ralentissement horaire (survenant environ 40 minutes après l'heure) qui peut contribuer au problème. Vous devriez jeter un œil aux planificateurs de tâches sur le système d'exploitation / base de données.

Sur la base des données que vous avez fournies, ma prochaine étape serait de regarder la fréquence des temps de réponse (nombre de réponses sur l'axe Y vs durée sur X) mais en n'incluant que les URL qui présentent le délai d'attente (ou de préférence une URL à la fois) ). Sur un système typique, cela devrait suivre une distribution normale ou poisson - les demandes qui expirent peuvent simplement faire partie de la queue - auquel cas vous devez concentrer vos efforts sur le réglage général. OTOH si la distribution est bimodale, vous devez rechercher la contention quelque part dans votre code.

J'ai une autre pensée à ce sujet, basée sur le fait que vous recevez un grand nombre de demandes par jour et que vous ne semblez avoir des délais d'attente qu'aux heures de pointe (d'après les photos que vous avez publiées).

Il y a un article sur le blog Server Fault,Per Second Measurements Don't Cut It ... est-il possible que certaines de ces demandes rencontrent le même problème que l'équipe ServerFault a rencontré?

Nous avons découvert que nous rejetions des paquets assez fréquemment sur des interfaces à 1 Gbit / s à des débits de seulement 10-30 Mbits / s, ce qui nuit à nos performances. En effet, ce taux de 10 à 30 Mbits / s est vraiment le nombre de bits transférés par 5 minutes convertis en un taux d'une seconde. Lorsque nous avons creusé plus près avec Wireshark et utilisé un graphique d'E / S d'une milliseconde, nous avons vu que nous éclaterions fréquemment le débit de 1 Mbit par milliseconde des interfaces dites à 1 Gbit / s.