[sf 1.4.x] délai de réponse ahurissant [Résolu]

[erictomcat]

j'ai un module admin basé sur une table avec beaucoup d'enregistrement (12235) il est vrai mais je trouve que 224926ms cela fait beaucoup quand même:

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
Configuration 12 32.69 0 
Factories 1 112.57 0 
Action "asset/index" 1 223980.80 99 
Database (Doctrine) 6 0.08 0 
View "Success" for "asset/index" 1 555.60 0 
Partial "asset/_assets" 1 2.18 0 
Partial "asset/_flashes" 1 2.18 0 
Partial "asset/_list_header" 1 2.08 0 
Partial "asset/_filters" 1 202.13 0 
Partial "asset/_filters_field" 2 186.14 0 
Partial "asset/_list" 1 206.70 0 
Partial "asset/_list_th_tabular" 1 8.44 0 
Partial "asset/_pagination" 1 10.45 0 
Partial "asset/_list_td_batch_actions" 10 22.14 0 
Partial "asset/_list_td_tabular" 10 29.94 0 
Partial "asset/_list_td_actions" 10 28.06 0 
Partial "asset/_list_batch_actions" 1 3.47 0 
Partial "asset/_list_actions" 1 2.13 0 
Partial "asset/_list_footer" 1 1.67 0

surtout que j'ai modifié ma requete pour réduire l'accés a la base de données je n'en ai plus que 6.

mon schéma:

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
Asset:
  tableName: asset
  actAs: [Timestampable]
  columns:
    typeasset_id: integer
    value: string(255)
    groupasset_id: integer
    useit: boolean
    exist: boolean
    lastview: date
  indexes:
    unique1:
      fields: [typeasset_id,value,groupasset_id]
      type: unique
  relations:
    type:
      class: Typeasset
      local: typeasset_id
      foreign: id
      foreignAlias: listTypeAsset
      onDelete: CASCADE
    group:
      class: groupasset
      local: groupasset_id
      foreign: id
      foreignAlias: listGroupAsset

ma requete:

Code :

1
2
3
4
5
6
7
8
9
10
public function activeAsset(){
		set_time_limit(300);
		//die("dans active asset");
    	$q = $this->createQuery('a')
			->leftJoin('a.type')
			->leftJoin('a.group')
    		->where('lastview = ?', $this->getLastDate());
    	//die($q->getSqlQuery());
    	return $q;
	}

mon generator.yml

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
 
generator:
  class: sfDoctrineGenerator
  param:
    model_class:           asset
    theme:                 admin
    non_verbose_templates: true
    with_show:             true
    singular:              ~
    plural:                ~
    route_prefix:          asset
    with_doctrine_route:   true
    actions_base_class:    sfActions
 
    config:
      actions: ~
      fields:  ~
      list:    
        display: [group, type, value]
        max_per_page: 10
        object_actions:          
          #Detail: ~    
          _edit: ~     
        table_method: activeAsset
      filter:  
        display: [typeasset_id, site]
      form:    ~
      edit:    ~
      new:     ~

[Michel Rotta]

Tu peux déjà rajouter un index sur lastdate.

Après, je ne sais pas sur quel machine tu travailles (dev ou prod) si ton test est en dev ou prod, ce qui peut changer notablement les performances. Si tu as un accélérateur sur ton serveur (genre APC) si certaines partie de l'écran pourraient être mises en cache.

Il y a beaucoup de pistes pour accélérer, moins que pour ralentir mais il en reste

[Vivian Pennel]

Peux-tu transmettre le log des requêtes SQL ? (dernier bouton de la debug bar)

Au vu du log de profiling, j'ai pas l'impression que le problème vienne de la base de données mais plutôt de l'hydratation ou de la vue.

Accessoirement est-ce que tu développes sous windows ?

[erictomcat]

le log sql:

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
 
SQL queries
Doctrine Version: 1.2.2
SET NAMES 'UTF8'
 
0.00s, "doctrine" connection
SELECT DISTINCT a.id AS a__id, a.lastview AS a__lastview FROM asset a ORDER BY a.lastview DESC
 
0.13s, "doctrine" connection
SELECT COUNT(*) AS num_results FROM (SELECT a.id FROM asset a LEFT JOIN typeasset t ON a.typeasset_id = t.id LEFT JOIN groupasset g ON a.groupasset_id = g.id WHERE a.lastview = '2010-11-01' GROUP BY a.id) dctrn_count_query
 
0.03s, "doctrine" connection
SELECT t.id AS t__id, t.name AS t__name FROM typeasset t
 
0.00s, "doctrine" connection
SELECT s.id AS s__id, s.name AS s__name, s.description AS s__description, s.manager_id AS s__manager_id, s.country_id AS s__country_id FROM site s
 
0.00s, "doctrine" connection
SELECT a.id AS a__id, a.typeasset_id AS a__typeasset_id, a.value AS a__value, a.groupasset_id AS a__groupasset_id, a.useit AS a__useit, a.exist AS a__exist, a.lastview AS a__lastview, a.created_at AS a__created_at, a.updated_at AS a__updated_at, t.id AS t__id, t.name AS t__name, g.id AS g__id, g.name AS g__name, g.site_id AS g__site_id, g.user_id AS g__user_id, g.status AS g__status, g.person AS g__person, g.lastview AS g__lastview, g.created_at AS g__created_at, g.updated_at AS g__updated_at FROM asset a LEFT JOIN typeasset t ON a.typeasset_id = t.id LEFT JOIN groupasset g ON a.groupasset_id = g.id WHERE (a.lastview = '2010-11-01') LIMIT 10
 
0.00s, "doctrine" connection

je suis sur la machine de test avec les données de prod. Mais comme c'est pour un intranet, la bécane de prod sera pas vraiment plus puissante :/

Je développe sous windows, pas le choix

ce qui m'étonne c'est que j'ai un autre module avec a peu prés autant de ligne et l'affichage est correcte..

EDIT: impossible d'editer un enregistrement j'ai un fatal error:

Code :

1
2
 
Fatal error: Maximum execution time of 30 seconds exceeded in C:\wamp\www\lib\vendor\symfony\lib\plugins\sfDoctrinePlugin\lib\vendor\doctrine\Doctrine\Collection.php on line 474

[Michel Rotta]

On doit pouvoir gagner quelques centièmes de secondes avec un index (pas plus de 10 !)

Pour le reste, quel est la configuration de la machine ?

Et pour l'édit, ne mélangeons pas tout, au risque de ne rien résoudre. Ici, les perf. Si tu as toujours le problème supplémentaire, ouvre un nouveau sujet, plus documenté.

[erictomcat]

bein pour moi le problème est le même.
Si je rajoute pas la ligne

Code :

set_time_limit(300)

dans le code de l'index, je me retrouve avec la même erreur

Code :

Fatal error: Maximum execution time of 30 seconds exceeded in C:\wamp\www\lib\vendor\symfony\lib\plugins\sfDoctrinePlugin\lib\vendor\doctrine\Doctrine\Collection.php on line 474

que dans l'édit.

De plus je vient de monter un module normal sur la même table et j'ai un affichage quasi immédiat.
Ce n'est donc pas un problème avec doctrine mais bien avec le traitement de symfony et son admin-generator.

PS: d'ailleurs j'ai retrouvé tes mail concernant les filtres. Je posterai un nouveau sujet le concernant, j'ai un point que je comprend pas

[Michel Rotta]

Tu n'as pas répondu à la question sur l'environnement.

Es-tu en environnement de débug quant tu tests ? Si oui, il faut savoir que le cache est régénéré à chaque affichage en debug, d'où des délais qui peuvent être notablement long, surtout en form d'administration. Dans ce cas, essaye hors debug, après un cc et fait plusieurs essais consécutif, cela devrait être visiblement plus rapide, même si tu n'auras pas les tableaux pour le démontrer (une montre ?)

[Inarius]

Alors déjà, une petite remarque: ta fonction assetList est censé prendre en paramètre un object Doctrine_Query. C'est ensuite à cet object que tu va rajouter des join, filtrages etc..

Ton assetList devrait donc ressembler à ceci:

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
 
public function activeAsset(Doctrine_Query $q){
	set_time_limit(300);
	//die("dans active asset");
 
        $a = $q->getRootAlias();
 
        $q = $q->leftJoin($a.'.type')
			->leftJoin($a.'.group')
    		->where($a.'.lastview = ?', $this->getLastDate());
    	//die($q->getSqlQuery());
    	return $q;
	}

Ensuite, il semblerait que ce soit lors de l'hydratation des résultats que ce soit si lent. En effet, c'est ton action "index" qui prend 99% du temps a être éxécuter et la requête SQL s'éxecute en quelques ms seulement.

Ce que tu peut regarder, c'est par exemple le nombre de ligne retourner par ta requete SQL ( et la je connais pas d'autre solution que d'éxecuter directement la requête sur le serveur SQL ).
Si ce nombre est énorme ( plus de 10000 ligne par exemple ), le problême peut venir d'ici. Il faut donc par exemple diminuer le nombre de join.

[Vivian Pennel]

Fais les tests suivants :

- Créé une action ou tu fais la même requête mais avec un

Code :

1
2
 
$query->execute(array(), Doctrine_Core::HYDRATE_ARRAY);

Redirige l'action sur un template vide. Puis regarde à nouveau les temps dans la debug bar.

- Dans ton action fais un execute() simple (avec hydratation donc) toujours sur un template vide.

Puis donnes nous les résultats.

Malheureusement, PHP et surtout symfony a de gros problèmes de performances sous windows (notamment pour le rendu des templates ..). J'ai commencé aussi à développer sur windows mais j'ai vite migré sur un environnement linux à cause de ce problème..

[erictomcat]

ouh la, beaucoup de réponse

je vais essayer de faire une synthèse.

Je suis effectivement en environnement de dev mais avec les données de prod car en environnement de prod j'avais une page blanche (time exceeded dans le log d'apache). Donc le problème ne vient pas de l'environnement de prod.

Pour les test de la query, j'ai créé un autre module non admin donc en gros sans template, mais aussi sans filtre et l'affichage se fait en quelques secondes, donc ce n'est pas un problème de requête SQL. Mais effectivement le nombre de ligne avoisine les 15000 lignes.

Pour l'OS, je sais windows, c'est mal, mais je n'ai pas le choix.

PS: il faut que je voie ce que donne le module admin avec les données de dev, CAD 5 lignes à afficher.

[Michel Rotta]

Pour le poste de dev en Windows, je pense qu'on est une majorité ici. Par contre, rien ne t'empêche de monter un VirtualBox ou apparenté et d'y démarrer un Linux léger, style un debian sans interface graphique. Sur cette machine tu installe un XAMP et tu peux y faire tes test tranquilles, affichage sur ton windows de ce que la machine Linux donne.

Pour le message : time exceeded dans le log d'apache, tu as un paramètre dans le php.ini qui permet d'étendre le temps. Et ça me pose un problème, pourquoi un time exceeded hors débug et pas en debug, alors qu'il devrait être plus rapide ?

[erictomcat]

pour l'os, la machine de prod est sous Windows, pas le choix. Du moins tant que je n'aurait pas vendu mon idée.

pour le time exceeded en prod je l'avait peut être avant de mettre mon set_time_limit à 300. me souvient pas si j'ai fait des test en environnement prod depuis.

Mais bon en prod, comme en dev, le délai d'affichage de plusieurs secondes, voir minute n'est pas acceptable.

[nlefebvre1]

a tu verifier ton APC "Peu etre saturer" est ce que la memoire apache est suffisante ??

[erictomcat]

désolé, je sais pas ce qu'est un APC.

[Michel Rotta]

APC est un système de cache permettant d'accélérer PHP

Il est sur que cela peut apporter des gains de rapidité importants.

Maintenant, pour ton truc, il faudrait décomposer le code généré par l'admin générator et trouver ce qui, dans son module, prend tellement de temps. Je me demande si ce n'est pas une question d'hydratation des données, mais à voir.

[erictomcat]

j'ai bien l'impression que cela vient de la, même si je n'ai qu'une vague idée de ce que peut être l'hydratation;

comment décomposer mon code pour voir d'où ça vient ?

[Inarius]

Pour savoir ce qui prend tellement de temps, tu peut utiliser un débogueur ( comme xDebug). Cet outil te permettra d'éxécuter ton code pas à pas et donc savoir ce qui prend tellement de temps.

Si tu utilise netbeans, tu as un débogueur PHP intégrer.

EDIT :
Sinon comme c'est ton action index qui est très lente, tu peut copier coller le code générer ( dans cache/....../actions.class.php ) de ton action index, dans ton app/backend/modules/"ton_module"/actions/actions.class.php

Ensuite pour chaque ligne, tu met un petit timer que tu affiche. Tu verra donc bien quel ligne est la plus longue à éxécuter. Et ce sera une piste supplémentaire

[Michel Rotta]

+1 pour déboguer, quoique, pour les délais de réponses, je ne suis pas sur de l'intérêt.

L'hydratation c'est la transformation des données après leur récupération. Par défaut, doctrine crée un ensemble d'objet intelligent. Mais si tu as toutes les données voulue et qu'elles ne vont pas servir pour envoyer une demande de mise à jour, tu peux demander à les hydrater sous forme d'un tableau (plusieurs types possibles). C'est beaucoup moins gourmand en tous, moins de ressource, moins de place, moins de temps. Et aussi, plus de code pour modifier ni de méthode pour récupérer les données en relation, si elles n'ont pas été récupéré dans la requête de départ, c'est foutu.

Je ne sais pas ce que fait symfony dans le module d'administration.

[erictomcat]

pour le débogage avec mon installation WAMP j'ai xDebug mais il smble ne pas vouloir se connecter donc mort.

Pour mon problème, je vient de faire un test en essayant de rajouter les filters sur un module normal et bingo, ça plante time execeeded.
J'ai l'impression que c'est l'affichage des filtres qui pose problème.

Code :

( ! ) Fatal error: Maximum execution time of 300 seconds exceeded in C:\wamp\www\lib\vendor\symfony\lib\plugins\sfDoctrinePlugin\lib\vendor\doctrine\Doctrine\Collection.php on line 474

Code :

1
2
3
4
5
6
 
30 0.3329 14086184 Doctrine_Query_Abstract->execute( ) ..\sfWidgetFormDoctrineChoice.class.php:86 
31 0.8159 22968064 Doctrine_Hydrator->hydrateResultSet( ) ..\Abstract.php:1036 
32 0.8160 22968832 Doctrine_Hydrator_Graph->hydrateResultSet( ) ..\Hydrator.php:137 
33 300.1085 66706816 Doctrine_Access->offsetSet( ) ..\Access.php:0 
34 300.1086 66706848 Doctrine_Collection->add( ) ..\Access.php:131

[Inarius]

Comme tu l'a dit, il semblerait que ce soit à l'affichage d'un des filtres que le temps soit enorme. Essaye donc de sélectionner les filtres à afficher.

Par contre, je vient de regarder et dans la propriété "display" de tes "filters", tu affiche le champs "site". Or il n'est pas définit dans ton schema.yml
Donc je suppose qu'il s'agit d'une méthode "getSite()" que tu utilise dans ton modèle. C'est peut-être le fait de répéter 12000 fois cette méthode qui ralentit énormément les choses. De plus, tu ne peut pas utiliser cette méthode pour filtrer si ce n'est pas un champs, il me semble.