Comment débusquer un script bien caché ?

[littlegecko]

Bonjour,

Je ne suis pas sûr d'être dans la bonne rubrique mais c'est celle que je trouve le plus approchant.

J'ai depuis quelques temps un problème de charge sur mon serveur web.

Ce problème devient de plus en plus gênant et je n'arrive pas à identifier la source du problème.

Voici son comportement via le top ssh :

Phase 1 : La mémoire libre tombe à 18Mo

Phase 2 : Le swap tombe à 0k

Phase 3 : le CPU monte à ~100% système pendant quelques minutes

Phase 4 : le mémoire et le swap reprenne des forces mais le CPU passe à ~100% en attente pendant plusieurs minutes

Donc là je me dis qu'il doit y avoir un script qui boucle quelque part ou alors trop requêtes SQL mal faite d'un coup.

Mon problème est que le site fait maintenant beaucoup beaucoup de lignes de code réparties dans beaucoup beaucoup de fichiers programmés par différentes personnes et qu'en plus on était partie d'un CMS à savoir NPDS.

Afin d'orienter mes recherches vers le méchant script j'ai mené différentes action notamment :

1. httpd.conf : baisser le timeout de 300 à 30... Bon oki c'est une technique de lâche et je me retrouve avec le même problème mais moins souvent.

2. MySQL : récupérer les logs de log-queries-not-using-indexes et log-slow-queries.

Suite à cette 2ème action, je me suis rendu compte qu'effectivement jétais un peu bourrin sur les order by de mes principales requête et j'ai donc réduit ceux-ci. Mais une autre ligne a attirée mon attention et rien à faire je ne sais pas d'où elle peut bien provenir :

# administrator command: Init DB;
# User_AT_Host: root[root] @ localhost []
# Query_time: 32  Lock_time: 0  Rows_sent: 0  Rows_examined: 140114930998448
SET timestamp=1233741134;
# administrator command: Init DB;

Bon celle-ci cest la suprême car jai régulièrement cette ligne mais avec moins de lignes examinées voir aucune.

Donc j'ai 3 questions :

1. A quoi sert cette requête sans table qui me crawl toute ma base de donnée ? Est-elle vraiment utile ? Comment puis-je l'enlever ?

2. Auriez-vous d'autre piste me permettant d'identifier mon problème ?

3. Il m'arrive de constater dans le top, un httpd qui traine avec lui quasi 100% de la mémoire. Y a t-il un moyen d'identifier ce qui l'a déclenché ?

Merci

Modifié 4 Février 2009 par littlegecko

[Kioob]

Hello,

pour moi le "Rows_examined: 140114930998448" indique surtout un bug : la connexion est en cours d'initialisation, et mysql affiche une variable interne probablement non initialisée. Bref, il ne parcourt pas toute la base non.

Par contre 30 secondes sur un "Init DB", pour ma part je rencontre deux cas possibles : un bug réseau (paquets perdus etc) qui fait que la connexion déconne en cours de route (déjà vécu, mais c'est quand même assez peu courant), ou un gros ralentissement du serveur qui fait que la moindre instruction soit très lente (c'est entre autre le cas quand ça swap). Si c'est provoqué par le swap, le problème vient d'ailleurs.

3. Il m'arrive de constater dans le top, un httpd qui traine avec lui quasi 100% de la mémoire. Y a t-il un moyen d'identifier ce qui l'a déclenché ?

Il y a divers solutions, mais rien de bien simple.

En modifiant le code de PHP tu peux tracer la mémoire consommée par mysql_query(), qui est parfois énorme et n'apparaît nul part coté PHP. Mais je ne sais pas si c'est à ta portée ; si ça l'est, je peux te procurer un (vieux) patch qu'il faudra peut être adapter.

Sinon en plaçant un script en "auto_prepend" tu peux forcer l'exécution en fin de script d'une fonction PHP sur l'ensemble du serveur qui mesurerait la consommation mémoire, le temps écoulé, et tracerait dans les logs tout ce qui dépasse un certain seuil.

J'utilise ces deux dernières techniques sur un service d'hébergement gratuit afin de mesurer la consommation client ; maintenant si quelqu'un connaît une autre approche, je suis également preneur.

[littlegecko]

Pour le temps d'exécution de la requête, je pense plus que ça vient de la surcharge serveur.

Je me penche sur tes suggestions.

En attendant, voici un copicol du top montrant le vilain httpd :

 
PID | USER | PR | NI | VIRT | RES | SHR | S | %CPU | %MEM | TIME+ | COMMAND
7713 | nobody | 20 | 0 | 4614m | 3.6g | 1276 | D | 2 | 93.8 | 0:06.82 | httpd

N'y aurait-il pas un moyen de forcer le serveur à arrêter un processus qui prendrait trop de mémoire ?

En même temps j'ai beau essayer de lui envoyer des kill 7713, il reste toujours bien vivant....

La commande reboot ne donne rien.

Seule solution restante, le reboot hard via l'interface web de l'hebergeur

Ou attendre que le processus s'arrête...

Modifié 5 Février 2009 par littlegecko

[Kioob]

Avec "ulimit" il doit y avoir moyen de limiter la quantité de mémoire utilisée par "nobody". Coté PHP, suhosin peut également aider à limiter les choses, selon ce qui consomme cette mémoire.

Sinon un simple cron qui zigouille tous les processus httpd de plus de 100Mo reste une solution pour éviter le crash... mais ce n'est pas ça qui t'indiquera d'où vient le problème.

Sinon, un "kill -9 7713" tuera le processus. Mais faut pas en abuser

[f_trt]

Je t'apporte pas beaucoup de solution mais tu peux faire aussi un arrêt de httpd ou un restart ce sera tjrs mieux que le hardreboot.

Tu peux peut-être si tu as une idée du site le mettre ailleurs et procéder par élimination.

[littlegecko]

tu peux faire aussi un arrêt de httpd ou un restart ce sera tjrs mieux que le hardreboot.

Oui oui je ne fais un hardreboot que si je n'ai plus la main sur le ssh.

Sinon j'ai regardé du coté de ulimit mais cela n'agit que sur le shell en cours et non les autres utilisateurs.

Je vais regarder un peu plus suhosin.

Je vais regarder aussi comment fonctionne la programmation d'un cron... le plus important étant que le site ne soit pas inaccessible.

Sinon j'ai tenter de configurer le fichier /etc/security/limits.conf mais ca n'a pas eu d'effet et le serveur continue de planter de temps en temps.

Voici comment j'ai parametrer le fichier limits.conf

nobody		  hard	core			200000
nobody		  hard	memlock		 200000
nobody		  hard	cpu			 1

J'avais mis des _AT_nobody au lieu des nobody mais ca ne fonctionnait pas plus.

Je viens également de mettre en place un log qui me rapportera toutes les pages qui ont mises plus de 20 secondes à s'afficher afin de pouvoir un peu mieux cerner d'où vient le problème.

Kioob, je suis intéressé par ton script pour mysql_query. Je ne sais pas si c'est à ma porté mais je vais essayer

Merci de votre aide

[Kioob]

Pour mysql_query ce n'est pas un script mais un patch, à appliquer à l'extension mysql de PHP avant compilation donc.

A l'époque c'était pour la version 5.2.0 de PHP fournie en etch : http://daevel.fr/200-mysql.min_stored_data.patch

Pour limits, je ne suis pas certain que ça fonctionne en module Apache... la limite serait alors probablement globale et non par script.

[devorigin]

Il existe aussi une option de mysql qui te permet de logguer les requêtes particulièrement lentes :

http://dev.mysql.com/doc/refman/5.1/en/slow-query-log.html

[littlegecko]

Oui j'ai mis en place les logs des requêtes longues et avec des index manquants mais rien de curieux n'est ressorti.

J'ai finalement créé un script shell qui kill les processus de "nobody" qui squatte 10% de la mémoire.

Technique de nul je sais mais j'ai tellement de développement impactant l'ensemble des visiteurs du site à faire que je chercherai la partie du code qui pose problème plus tard. Surtout que suite à la suppression d'un bloc, le nombre de fois que le script fusible s'active a sacrément diminué. (de 3-4 fois par heures à 2-3 fois par jours)

Je vous fais un petit copié collé du script si ça intéresse certains :

#!/bin/sh
#set -xv

tab=($(ps -C fusible.sh | awk '{print($1)}'))
ok=0
i=0
while [ "$i" -lt "${#tab[*]}" ]
do
		pid=${tab[$i]}
		if [ "$pid" != "PID" ]
		then
				((ok++))
		fi
		((i++))
done

if [ "$ok" -lt 3 ]
then
		limit="10"
		log="/var/log/antiplantage.log"
		echo $(date) " : ALERT relance du fusible !">> $log
		while [ 1 ]
		do
				tab=($(ps v U nobody | awk '{print($1,$9)}'))
				i=0
				while [ "$i" -lt "${#tab[*]}" ]
				do
						pid=${tab[$i]}
						mem=${tab[$i+1]}
						if [ "$pid" != "PID" ]
						then
								COMP=$(echo "$mem>$limit" | bc)
								if [ $COMP -eq 1 ]
								then
										echo $(date) " : " $pid " = " $mem " %">> $log
										kill -15 $pid
										sleep 1
										kill -9 $pid
								fi
						fi
						((i=i+2))
				done
				#echo $(date) " OK" >> $log
		done
fi

Petite explication :

Le script est lancé par un cron toutes les minutes car il avait tendance à disparaître au bout d'un moment.

Chose curieuse, lorsque je le lance, il prend 2 PID dont 1 qui change à chaque ps.

Pour vérifier la non présence d'un autre script fusible, je vérifie alors qu'il n'est présent que sur 2 PID.

Si c'est le cas, il continue et inscrit une alerte dans le log.

Ensuite je boucle et double kill tous les processus > 10% de charge mémoire.

Au début, je faisais un sleep 30 pour ne boucler que toutes les 30 secondes mais la vitesse à laquelle le script malicieux charge la mémoire est telle que j'ai dû me résoudre à boucler en continue.

Ce script fusible.sh, prend 7 à 8% d'occupation processeur et rien en mémoire.

Encore merci pour votre aide.

Je me pencherai plus sur le sujet à mes heures perdues et vous tiendrai au courant sur ce que je trouve.

Je reste toutefois ouvert à toute suggestion me permettant de pister les raisons de ralentissements d'un serveur web php/mysql.