Discussion :

[petozak]

Bonjour,
J'ai une interface qui tourne sur un serveur de prod dont les indicateurs (top sous Unix à 2.0 max) sont bons et pourtant j'ai des perfs lamentables autour de 10h de traitement.
Cette même interface met 3h30 à 4h sous windows sachant que je l'ai developpée sous et compilé sous Windows/Eclipse.

[*alexandre*]

Etonnant,

Quel type de traitement ton programme fait ?

Quels programmes utilisent-t-il ?

[natha]

Quelles librairies natives sont utilisées ?
Car peut-être que tu utilises des librairies nulles en Unix et quelles sont bonnes en Windows.

Il faut plus d'infos détaillées pour qu'on puisse répondre à ce genre de question.

[petozak]

Au fait, j'ai passé hier à potasser la doc GC.
Le problème ne vient pas de l'OS mais du serveur sur lequel , je fais tourner l'interface (qui fait du traitement via une API d'un progiciel).
En effet sur le serveur de Prod: (Unix)
Full GC dure de 5 à 6 sec
Sur le Serveur de Dev (Unix)
Full GC dure de 1 à 2 sec
Etant donné que l'interface est pas super bien codé notamment avec des appels explicité à system.gc() toutes les iterations , je vous laisse imaginer la degradation de perf...
Je suis en train de tenter :
-XX:+DisableExplicitGC
Pour desactiver les appels à system.gc()...

Si vous avez des idees...
(la memoire free est de 1800 Mo sur les 2 serveurs et 9G de free Swap)
Le Top donne un bon load average qui depasse pas les 2

J'attend vos conseils d'optimisation

Voila

[natha]

Etant donné que l'interface est pas super bien codé notamment avec des appels explicité à system.gc() toutes les iterations

Oula d'accord, je comprends mieux ! Genre le truc à pas faire par excellence

[petozak]

Oula d'accord, je comprends mieux ! Genre le truc à pas faire par excellence

Je plaide innoncent... je ne l'ai pas fait .
Moi je tente d'optimiser...

[natha]

Je plaide innoncent... je ne l'ai pas fait .
Moi je tente d'optimiser...

Bah déjà faut tous les virer ces appels GC, vérifie également que tu tournes sur une JVM en mode serveur et teste voir si ça améliore.
Accessoirement surveille la consommation mémoire de ton applic pendant le test (si tu utilises java5 ou plus tu as jconsole qui est bien pratique ma foi).

Après on ne peut pas vraiment te dire comment optimiser... faut plus de détails. On n'est pas magiciens.

[petozak]

Bon bonne nouvelle , je passe d'un temps traitement de 10h à 2h waw!!
Sans les Full GC c'est genial...par contre mon me tanne pour savoir pourquoi les Full GC sont aussi long sur notre serveur de prod...
d'ou ca peut venir?
(On est en "1.4.2_06" alors qu'en dev , on est en 1.5_11 mais bon ca n'explique pas pour moi)

[sinok]

Euh vu les diffs de perfs entre la 1.4 et la 1.5 c'est compréhensible (d'ailleurs c'est pas forcément une bonne idée de travailler avec des versions diffférentes entre les environnements de prod et de dev).

Et le GC est une bestiole qui peut te bouffer un bon paquet de mêmoire les temps de vérifier toutes les références. D'autant plus que tu ne gères pas réellement le moment ou il intervient. Mieux vaut ne pas trop l'emmerder et le laisser faire tranquillement son boulot dans son coin

[petozak]

Euh vu les diffs de perfs entre la 1.4 et la 1.5 c'est compréhensible (d'ailleurs c'est pas forcément une bonne idée de travailler avec des versions diffférentes entre les environnements de prod et de dev).

Tu crois vraiment que sun a reussi à gagner autant au niveau des system.gc() (full gc)?
C'est aussi revolutionnaire que ca la 1.5?

[adiGuba]

Salut,

Bon bonne nouvelle , je passe d'un temps traitement de 10h à 2h waw!!
Sans les Full GC c'est genial...par contre mon me tanne pour savoir pourquoi les Full GC sont aussi long sur notre serveur de prod...
d'ou ca peut venir?
(On est en "1.4.2_06" alors qu'en dev , on est en 1.5_11 mais bon ca n'explique pas pour moi)

Je dirais que c'est parce que le GC fait bien son boulot tout seul... en libérant la mémoire quand il le faut. Pour cela il utilise deux types de libérations les minors collections et les majors collections (bien plus gourmande en temps). Pour plus d'info : http://gfx.developpez.com/tutoriel/java/gc/


En appelant explicitement System.gc() on le force à faire le ménage... ce qui peut être pénalisant !


Un exemple : la création de 50000 objets dans un boucle :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
	System.out.println("START");
	for (int i = 50000; i>0; i--) {
		Object o = new Object();
	}
	System.out.println("END");

Lorsque j'exécute ce code avec l'option -verboce:gc de la JVM (ce qui permet de logger le passage du GC), j'obtiens ceci :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
START
[GC 512K->102K(1984K), 0.0080338 secs]
END

Le GC effectue seulement une minor collection qui dure environ 8 millisecondes, et fait descendre la mémoire de 512K à 102k. Le programme s'exécute en quelques ms...



Maintenant si je force le passage du GC à chaque itération :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
	System.out.println("START");	
	for (int i = 50000; i>0; i--) {
		Object o = new Object();
		System.gc();
	}
	System.out.println("END");

J'obtiens ceci :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
START
[Full GC 148K->102K(1984K), 0.0420998 secs]
[Full GC 102K->102K(1984K), 0.0406980 secs]
[Full GC 102K->102K(1984K), 0.0422317 secs]
[Full GC 102K->102K(1984K), 0.0385216 secs]
[Full GC 102K->102K(1984K), 0.0447407 secs]
(...)

J'ai bien sûr tronqué le résultat, car le programme est très long (et je n'ai pas eu le courage d'attendre jusqu'à la fin... En fait il y a une major collection (Full GC) à chaque itération... et chaque "Full GC" prend environ 40ms... Si on calcule bien au final cela représente plus de 30 minutes !!!

Tout cela pour libérer un seul objet ! Le problème est que les "Full GC" sont bien plus couteux, et qu'ils sont appelés inutilement...


Bref : System.gc() est vraiment à utiliser dans des cas très rare, et surtout pas dans une boucle !!!



Quand à la différence entre le serveur de dev et de prod, cela vient surement du fait que le System.gc() n'est pas forcément exécuté. Ce n'est qu'une suggestion et la JVM peut l'ignoré (Utilise -verboce:gc pour vérifier cela -- attention car ceci peut être couteux car cela génère de gros logs).


a++

[petozak]

Salut,



Je dirais que c'est parce que le GC fait bien son boulot tout seul... en libérant la mémoire quand il le faut. Pour cela il utilise deux types de libérations les minors collections et les majors collections (bien plus gourmande en temps). Pour plus d'info : http://gfx.developpez.com/tutoriel/java/gc/


En appelant explicitement System.gc() on le force à faire le ménage... ce qui peut être pénalisant !


Un exemple : la création de 50000 objets dans un boucle :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
	System.out.println("START");
	for (int i = 50000; i>0; i--) {
		Object o = new Object();
	}
	System.out.println("END");

Lorsque j'exécute ce code avec l'option -verboce:gc de la JVM (ce qui permet de logger le passage du GC), j'obtiens ceci :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
START
[GC 512K->102K(1984K), 0.0080338 secs]
END

Le GC effectue seulement une minor collection qui dure environ 8 millisecondes, et fait descendre la mémoire de 512K à 102k. Le programme s'exécute en quelques ms...



Maintenant si je force le passage du GC à chaque itération :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
	System.out.println("START");	
	for (int i = 50000; i>0; i--) {
		Object o = new Object();
		System.gc();
	}
	System.out.println("END");

J'obtiens ceci :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
START
[Full GC 148K->102K(1984K), 0.0420998 secs]
[Full GC 102K->102K(1984K), 0.0406980 secs]
[Full GC 102K->102K(1984K), 0.0422317 secs]
[Full GC 102K->102K(1984K), 0.0385216 secs]
[Full GC 102K->102K(1984K), 0.0447407 secs]
(...)

J'ai bien sûr tronqué le résultat, car le programme est très long (et je n'ai pas eu le courage d'attendre jusqu'à la fin... En fait il y a une major collection (Full GC) à chaque itération... et chaque "Full GC" prend environ 40ms... Si on calcule bien au final cela représente plus de 30 minutes !!!

Tout cela pour libérer un seul objet ! Le problème est que les "Full GC" sont bien plus couteux, et qu'ils sont appelés inutilement...


Bref : System.gc() est vraiment à utiliser dans des cas très rare, et surtout pas dans une boucle !!!



Quand à la différence entre le serveur de dev et de prod, cela vient surement du fait que le System.gc() n'est pas forcément exécuté. Ce n'est qu'une suggestion et la JVM peut l'ignoré (Utilise -verboce:gc pour vérifier cela -- attention car ceci peut être couteux car cela génère de gros logs).


a++

Merci c'est tres instructif.
Et sinon la jvm 1.5 est elle à ce point plus performante que la 1.4 pour le Full GC?

[petozak]

Au fait j'utilise verbose , sinon je pourrai vous dire les temps des FGC ...
Apparement la jvm 1.5 gere bien mieux les major collection.

[Gfx]

La JVM 1.5 a apporté pas mal d'améliorations au GC, elle en vaut largement la peine. Il est également intéressant de bien comprendre comment le GC fait son travail et surtout quels algorithmes de GC sont disponibles et comment les paramétrer. Cela va bien plus loin que le choix entre la JVM server et client (qui interviennent plus sur le JIT en fait). En outre, le paramétrage du GC doit vraiment se faire au cas par cas. Cela dépend donc vraiment de ton application (crée-t'elle beaucoup d'objets temporaires ? beaucoup d'objets avec une longue durée de vie ? etc.) et du hardware (un ou plusieurs CPU ? combien de RAM ? etc.).

Si tu tournes avec J2SE 1.5, essaye très vite l'outil jconsole qui te permet d'observer le comportement du GC. Sinon, tu peux faire comme dans mon article et écrire des scripts pour analyser les traces du GC et créer des graphes sous OpenOffice.org/Excel pour voir un peu mieux ce qu'il se passe.

Une chose est sûre, il *faut* supprimer tous ces appels à System.gc(). Souviens-toi que le GC interrompt l'exécution de l'application.

Je te conseille également d'utiliser un bon profiler (cf celui de NetBeans ou jconsole) pour vérifier que vous ne leakez pas de la mémoire dans le tenured space. Cela pourrait expliquer la lenteur des major collections. Des appels à gc() n'arrangeront en rien les choses, ou seulement temporairement.

[petozak]

Merci GFX.
J'ai récupéré les temps totaux squattés par le GC est finalement je passe de 16 min à 1min42 apres avoir tweaker à mon amximum la Jvm.
Le temps d'execution est tres long (tres gros objets à exporter)...je vais essayer de tweaker hibernate ou au mieux améliorer l'algo.
Merci à Tous.
Un post plus qu'instructif