test de performance logiciel LAMP (P=Perl)

L'affichage de certaines pages demande un délai sensible, donc trop long
(je parle là de <2 secondes. Disons que c'est pas immédiat).

Comment faire pour pister l'origine du problème ? Je vois les
possibilités suivantes :
* temps de compilation du script Perl+ des bib du cpan (MARC::Record,
NET::Z3950) + des bib "maisons" (pour environ 150ko de script -hors
packages cpan-)

Un perl -cw devrait vous donner une idée du temps de compilation.

* temps d'exécution du script (une imbrication de boucles qui ferait 100
000 fois un truc alors qu'on pourrait optimiser)

Vous pouvez faire des benchmarks, par exemple Benchmark::Timer permettra
de voir quelles parties du code sont les plus lentes.

* erreur de conception
dans la base (j'ai bien cherché, je ne pense pas que ce soit ça.
D'autant que le pb est le même avec une base quasi vide et une base très
chargée)

Vous pouvez toujours augmenter le niveau de log, voir les requêtes SQL
qui sont faites, voir les plus longues, et essayer de voir si vous pouvez
les optimiser.
Une amélioration du schéma peut être possible aussi, ca dépend.
Mais avec l'étape précédente vous avez pu déjà normalement voir où ca
bloque au niveau du code. Si c'est au niveau des requêtes SQL, faut voir
quoi faire de ce côté là, mais ce n'est effectivement pas nécessairement
là que vous allez y gagner le plus.

* temps de rendu de mozilla sur le poste client (sachant que le HTML
généré est "simple". Et sur les pages avec peu de traitement, le délai
est nettement moindre)

Faire des tests en local, ce qui élimine la partie temps de transport et
temps de rendu du navigateur.
Par exemple avec ab (apache benchmark)

* c'est la mandrake 9.2 / Apache 2.0 qui sont mal compilés ou je sais
pas trop quoi d'autre.

La compilation peut jouer sur les performances, oui.
Vous pouvez toujours essayer de recompiler un apache 2.0 ``à la main''
pour voir si cela change quelque chose. Ou essayer de voir comment

A l'occasion, vérifiez avec un apache 1.x aussi.

Il y en a peut être d'autres.

La machine est-elle chargée ? A-t-elle assez de RAM ?

Et il y a peut être des outils simples à mettre en oeuvre pour tracer
certains éléments ?
Voire des solutions pour accélérer le tout (je connais déjà mod-perl et
fast::cgi, mais on n'a pas essayé)

Normalement, s'il n'y a pas trop ``d'horreurs'' (variables globales,
etc...) un script CGI quelconque écrit en Perl peut passer en mod-perl
(Registry) et donc profiter d'un gain en performances.
Problème: mod_perl 2 (en pratique 1.99.quelque chose) n'est pas vraiment
encore stabilisé, notamment parce qu'Apache ne semble pas vraiment
l'être.

Patrick.

Le Thu, 12 Feb 2004 09:59:38 +0100, paul écrivait:

Et il y a peut être des outils simples à mettre en oeuvre pour tracer
certains éléments ?

Il y a un module "profiler" pour perl, qui est normalement fait pour
découvrir les points de friction, justement.

Voire des solutions pour accélérer le tout (je connais déjà mod-perl et
fast::cgi, mais on n'a pas essayé)

Normalement en mod_perl c'est BEAUCOUP plus rapide, parce que
l'interpréteur perl reste lancé dans apache, au lieu de démarrer à
chaque lancement de script ce qui introduit une latence importante.

--
Quidquid latine dictum sit, altum sonatur

Le Thu, 12 Feb 2004 11:11:21 +0100, Emmanuel Florac écrivait:

Il y a un module "profiler" pour perl, qui est normalement fait pour
découvrir les points de friction, justement.

C'est là:

http://www.perldoc.com/perl5.8.0/lib/Devel/DProf.html

--
Le commissaire : Comment vous appelez-vous?
Garance : Moi je ne m'appelle jamais, je suis toujours là. J'ai pas
besoin de m'appeler. Mais les autres m'appellent Garance, si ça peut
vous intéresser.
Prévert,"les enfants du Paradis".

À (at) Thu, 12 Feb 2004 09:59:38 +0100,
paul <paul.poulain_nospam@free.fr.invalid> écrivait (wrote):

Je vois les possibilités suivantes :
[...]

Il y a un temps incompressible que vous avez oublié : le temps pour le serveur
Apache de forker un nouveau processus. Ce temps est indépendant de la nature
du CGI (script Perl ou non, programme en C ou en C++). Ce temps est loin
d'être négligeable. Un autre temps non négligeable est le temps de connexion à
la base de données (là ça dépend de la base).

Dans tous les cas, la solution passe par mod_perl ou par FastCGI (qui est plus
simple à mettre en oeuvre que mod_perl).


--
Paul Gaborit - <http://www.enstimac.fr/~gaborit/>
Perl en français - <http://www.enstimac.fr/Perl/>

Emmanuel Florac wrote:

Le Thu, 12 Feb 2004 09:59:38 +0100, paul écrivait:

Et il y a peut être des outils simples à mettre en oeuvre pour tracer
certains éléments ?

Il y a un module "profiler" pour perl, qui est normalement fait pour
découvrir les points de friction, justement.

Excellent le profiler. Hop, dans mes bookmarks...

Ca donne ca :
Exporter::export_ok_tags has -1 unstacked calls in outer
CGI::_set_attributes has 1 unstacked calls in outer
CGI::escapeHTML has 1 unstacked calls in outer
CGI::delete has 1 unstacked calls in outer
CGI::AUTOLOAD has -11 unstacked calls in outer
POSIX::load_imports has 1 unstacked calls in outer
POSIX::AUTOLOAD has -1 unstacked calls in outer
Exporter::Heavy::heavy_export has 27 unstacked calls in outer
CGI::register_parameter has 1 unstacked calls in outer
CGI::cookie has 1 unstacked calls in outer
CGI::previous_or_default has 1 unstacked calls in outer
Exporter::Heavy::heavy_export_ok_tags has 1 unstacked calls in outer
CGI::scrolling_list has 1 unstacked calls in outer
CGI::header has 1 unstacked calls in outer
Exporter::export has -27 unstacked calls in outer
CGI::_set_values_and_labels has 1 unstacked calls in outer
CGI::cache has 1 unstacked calls in outer
CGI::read_from_cmdline has 1 unstacked calls in outer
Total Elapsed Time = 2.278924 Seconds
User+System Time = 0.868924 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
16.1 0.140 0.160 4 0.0350 0.0399 C4::Date::BEGIN
14.3 0.125 0.206 1 0.1246 0.2059 main::build_tabs
8.06 0.070 0.398 7 0.0100 0.0569 C4::Auth::BEGIN
7.48 0.065 0.065 16860 0.0000 0.0000
C4::Koha::subfield_is_koha_interna
l_p
6.91 0.060 0.508 42 0.0014 0.0121 main::BEGIN
5.64 0.049 0.048 943 0.0001 0.0001 HTML::Template::param
4.60 0.040 0.200 5 0.0080 0.0399 C4::Reserves2::BEGIN
4.60 0.040 0.069 6 0.0066 0.0116 C4::Context::BEGIN
4.37 0.038 0.055 1 0.0377 0.0555 C4::Biblio::MARCgettagslib
3.45 0.030 0.030 1 0.0300 0.0298
C4::Interface::CGI::Output::output
_html_with_http_headers
3.45 0.030 0.050 6 0.0050 0.0083 C4::Output::BEGIN
2.30 0.020 0.020 11 0.0018 0.0018 CGI::_compile
2.30 0.020 0.020 5 0.0040 0.0040 C4::Biblio::BEGIN
2.30 0.020 0.020 65 0.0003 0.0003 Exporter::import
2.30 0.020 0.017 70 0.0003 0.0002 main::create_input


J'en conclus pas grand chose d'évident...
quelques questions cependant :
* le temps écoulé est nettement inférieur au temps user+system : cela
signifie t'il que c'est mySQL qui est le goulot d'étranglement ? (je
précise que le subfield_is_koha_internal_p appelé 16860 fois ne fait RIEN
au niveau SQL. C'est une bète fonction booléenne, qu'on aurait même pu
éviter de définir, probablement). Si oui, comment chercher plus
précisémment ?
* pourquoi C4::Date est il si "long" à s'exécuter ? C'est un bète truc qui
utilise Date::Manip et qui comporte 3 fonctions sans aucune boucle (juste
2-3 if)
* les "unstacked calls in outer" peuvent ils être à l'origine d'un
quelconque problème ?
--
Paul

paul wrote:

Bonjour,

Soit un logiciel métier sous licence libre basé sur une plateforme
Linux-Apache-mySQL-Perl (mais pas mod-Perl) installé sur une plateforme
mandrake 9.2 et un athlon 1500+ qui fait à la fois serveur et client.
mySQL étant bien configuré et n'étant pas la source du problème.

L'affichage de certaines pages demande un délai sensible, donc trop long (je
parle là de <2 secondes. Disons que c'est pas immédiat).

Comment faire pour pister l'origine du problème ?
Je vois les possibilités suivantes :
* temps de compilation du script Perl+ des bib du cpan (MARC::Record,
NET::Z3950) + des bib "maisons" (pour environ 150ko de script -hors
packages cpan-)
Effectivement, mod_perl pourrait accelerer le processus.

* temps d'exécution du script (une imbrication de boucles qui ferait 100 000
fois un truc alors qu'on pourrait optimiser)
Ben ca c'est sur mais bon, si ya 150ko de scripts, va falloir fouiller !

* erreur de conception dans la base (j'ai bien cherché, je ne pense pas que
ce soit ça. D'autant que le pb est le même avec une base quasi vide et une
base très chargée)
Oubli de creation d'indexes dans ta base sur des champs de requetes. Ca

c'est vachement important !! Ca peut donner des resultats 10 voir 50
fois plus rapides, même sur une petite base.

* temps de rendu de mozilla sur le poste client (sachant que le HTML généré
est "simple". Et sur les pages avec peu de traitement, le délai est
nettement moindre)
Essaye de juste telecharger le resultat a coups de wget, pour juger,

mais je pense reellement que c'est negligeable.

* c'est la mandrake 9.2 / Apache 2.0 qui sont mal compilés ou je sais pas
trop quoi d'autre.
Au mieux tu gagne 10% en recompilant.

--
Thomas Pedoussaut
Dublin IRLANDE
http://irlande.staffeurs.org/

paul wrote:

Emmanuel Florac wrote:

Le Thu, 12 Feb 2004 09:59:38 +0100, paul écrivait:

Et il y a peut être des outils simples à mettre en oeuvre pour tracer
certains éléments ?

Il y a un module "profiler" pour perl, qui est normalement fait pour
découvrir les points de friction, justement.

Excellent le profiler. Hop, dans mes bookmarks...

Ca donne ca :
Exporter::export_ok_tags has -1 unstacked calls in outer
CGI::_set_attributes has 1 unstacked calls in outer
CGI::escapeHTML has 1 unstacked calls in outer
CGI::delete has 1 unstacked calls in outer
CGI::AUTOLOAD has -11 unstacked calls in outer
POSIX::load_imports has 1 unstacked calls in outer
POSIX::AUTOLOAD has -1 unstacked calls in outer
Exporter::Heavy::heavy_export has 27 unstacked calls in outer
CGI::register_parameter has 1 unstacked calls in outer
CGI::cookie has 1 unstacked calls in outer
CGI::previous_or_default has 1 unstacked calls in outer
Exporter::Heavy::heavy_export_ok_tags has 1 unstacked calls in outer
CGI::scrolling_list has 1 unstacked calls in outer
CGI::header has 1 unstacked calls in outer
Exporter::export has -27 unstacked calls in outer
CGI::_set_values_and_labels has 1 unstacked calls in outer
CGI::cache has 1 unstacked calls in outer
CGI::read_from_cmdline has 1 unstacked calls in outer
Total Elapsed Time = 2.278924 Seconds
User+System Time = 0.868924 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
16.1 0.140 0.160 4 0.0350 0.0399 C4::Date::BEGIN
14.3 0.125 0.206 1 0.1246 0.2059 main::build_tabs
8.06 0.070 0.398 7 0.0100 0.0569 C4::Auth::BEGIN
7.48 0.065 0.065 16860 0.0000 0.0000
C4::Koha::subfield_is_koha_interna
l_p
6.91 0.060 0.508 42 0.0014 0.0121 main::BEGIN
5.64 0.049 0.048 943 0.0001 0.0001 HTML::Template::param
4.60 0.040 0.200 5 0.0080 0.0399 C4::Reserves2::BEGIN
4.60 0.040 0.069 6 0.0066 0.0116 C4::Context::BEGIN
4.37 0.038 0.055 1 0.0377 0.0555 C4::Biblio::MARCgettagslib
3.45 0.030 0.030 1 0.0300 0.0298
C4::Interface::CGI::Output::output
_html_with_http_headers
3.45 0.030 0.050 6 0.0050 0.0083 C4::Output::BEGIN
2.30 0.020 0.020 11 0.0018 0.0018 CGI::_compile
2.30 0.020 0.020 5 0.0040 0.0040 C4::Biblio::BEGIN
2.30 0.020 0.020 65 0.0003 0.0003 Exporter::import
2.30 0.020 0.017 70 0.0003 0.0002 main::create_input


J'en conclus pas grand chose d'évident...

J'en conclus qu'une grande partie du temps d'execution consiste a
compiler ton script.

Essaie de faire tourner ton script sous SpeedyCGI:

http://www.daemoninc.com/SpeedyCGI/

Si ca tourne correctement sous SpeedyCGI, tu ne devrais pas avoir de
probleme majeur pour faire tourner avec Apache::Registry. Ton plan de
migration devrait etre le suivant:

1- Faire tourner les script sous SpeedyCGI # elimine compilation
2- Les passer sous Apache::Registry # elimite fork
3- Installer Apache::DBI # elimine connection MySQL


Ensuite il y a ce main::build_tabs qui a l'air de prendre pas mal de
temps... elle fait quoi cette fonction?

Sinon pour rendre les temps de compilation negligeables lorsque tu
utilise le profiler, je suggere que tu modifie ton script pour qu'il
fasse 50 fois la meme chose. Par exemple au lieu d'avoir qqchose comme:

main(); # demarre le script

Tu ecris:

for (1..50) { main() }; # fais la meme chose 50 fois
# pour rendre les temps de compil negligeables

quelques questions cependant :
* le temps écoulé est nettement inférieur au temps user+system : cela
signifie t'il que c'est mySQL qui est le goulot d'étranglement?

Essaie de diriger l'output de ton script vers >/dev/null, voire si c'est
pas ton xterm qui fait goulot d'etranglement.

(je précise que le subfield_is_koha_internal_p appelé 16860 fois ne fait RIEN
au niveau SQL. C'est une bète fonction booléenne, qu'on aurait même pu
éviter de définir, probablement).

Qui prend presque 7% du temps total d'execution. Inline?

Si oui, comment chercher plus précisémment?
* pourquoi C4::Date est il si "long" à s'exécuter ? C'est un bète truc qui
utilise Date::Manip et qui comporte 3 fonctions sans aucune boucle (juste
2-3 if)

Parce que Date::Manip est pas tres rapide. En fait c'est meme plutot lent.

* les "unstacked calls in outer" peuvent ils être à l'origine d'un
quelconque problème ?

Aucune idee :)

Paul GABORIT wrote:

FastCGI (qui est
plus simple à mettre en oeuvre que mod_perl).
Je ne comprends pas grand chose à FastCGI.

Ni comment on l'installe, ni comment on l'utilise.
de ce que j'ai compris, il faut une version spéciale de Perl (savvy ?), et
reprendre tous les scripts.
(source :
http://www.fastcgi.com/devkit/doc/fastcgi-prog-guide/ch3perl.htm#3659
)

--
Paul

Jean-Michel Hiver wrote:

J'en conclus pas grand chose d'évident...

J'en conclus qu'une grande partie du temps d'execution consiste a
compiler ton script.
C'est bien possible...

Essaie de faire tourner ton script sous SpeedyCGI:
http://www.daemoninc.com/SpeedyCGI/

apache2 n'a pas l'air d'aimer :
Cannot load /etc/httpd/2.0/modules/mod_speedycgi.so into server:
/etc/httpd/2.0/modules/mod_speedycgi.so: undefined symbol:
ap_suexec_enabled

Ensuite il y a ce main::build_tabs qui a l'air de prendre pas mal de
temps... elle fait quoi cette fonction?
C'est le coeur du script. Ca ne me choque pas qu'elle soit longue : elle lit

des tables de hachage, elle remplit des arrays, qui sont passés à
HTML::Template ensuite...
avec plein de boucles et de conditions.
Elle utilise aussi un objet MARC::Record (truc spécial/norme pour les
bibliothèques)

for (1..50) { main() }; # fais la meme chose 50 fois
# pour rendre les temps de compil negligeables
C'est une bonne idée :

Total Elapsed Time = 24.85507 Seconds
User+System Time = 16.95507 Seconds
soit <0,5 secondes par passage. On doit pouvoir optimiser quelques petites
choses...

quelques questions cependant :
* le temps écoulé est nettement inférieur au temps user+system : cela
signifie t'il que c'est mySQL qui est le goulot d'étranglement?

Essaie de diriger l'output de ton script vers >/dev/null, voire si c'est
pas ton xterm qui fait goulot d'etranglement.

Total Elapsed Time = 21.75507 Seconds
User+System Time = 16.44507 Seconds
on ne gagne pas grand chose.

(je précise que le subfield_is_koha_internal_p appelé 16860 fois ne fait
RIEN au niveau SQL. C'est une bète fonction booléenne, qu'on aurait même
pu éviter de définir, probablement).

Qui prend presque 7% du temps total d'execution. Inline?
on progresse doucement :

Total Elapsed Time = 19.26061 Seconds
User+System Time = 15.68061 Seconds

En limitant à une cinquantaine (au lieu de 1200) le nombre de lignes avec
lequel travailler dans build_tabs et dans C4::Biblio::MARCgettagslib,
j'obtiens :
Total Elapsed Time = 11.29172 Seconds
User+System Time = 8.981721 Seconds
et là, c'est HTML::Template qui est le + gros consommateur.

En conclusion :
De toutes manières, il y a un peu tout qui se cumule :
* une compilation du script longuette.
* le temps du fork...
* l'exécution, avec des calculs compliqués.
* le temps de rendu. J'ai négligé de dire que le HTML généré faisait 74ko,
ce qui est quand même pas rien ! (un masque de saisie avec une cinquantaine
de champs/listes..., sur 10 onglets qui s'affichent et cachent)
* le temps de "fabrication" des polices de caractères. Si je prends un
mozilla sans support xfs, c'est plus rapide !
--
Paul

On 2004-02-12, Thomas Pedoussaut <thomas@parinux.org> wrote:

Essaye de juste telecharger le resultat a coups de wget, pour juger,
mais je pense reellement que c'est negligeable.

A noter dans le même ordre d'idée le sympathique ab (Apache HTTP server
benchmarking tool) fourni avec apache.