I. Un Peu de théorie▲
Regardons la Javadoc.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
public
static
void
gc
(
)
Runs the garbage collector.
Calling the gc method suggests that the Java Virtual Machine expend effort toward recycling unused
objects in order to make the memory they currently occupy available for
quick reuse.
When control returns from the method call, the Java Virtual Machine has made a best effort to reclaim space from all discarded objects.
The call System.gc
(
) is effectively equivalent to the call:
Runtime.getRuntime
(
).gc
(
)
See Also:
Runtime.gc
(
)
Première mauvaise nouvelle, System.gc() ne réalise pas forcément un GC (il peut ne rien faire) et surtout on ne sait pas quand.
On a des chances de se retrouver dans ce cas.
Supposons que la JVM réagisse comme on le souhaite (le GC est bien exécuté), le GC ne s'exécutera pas forcément au meilleur moment par rapport à l'état de la JVM. Le tout en gardant le coût d'un GC (qui en fonction d'un certain nombre de paramètres peut aller jusqu'à plusieurs secondes).
II. Passons à la pratique▲
Afin de tester notre hypothèse (ne pas utiliser de System.gc()) modifions l'application Spring Pet Clinic en lui ajoutant un appel au GC.
Créons un scénario JMeter afin de simuler de l'activité.
II-A. Exécutons notre scénario avec un seul utilisateur▲
On remarque que l'activité GC est énorme (plus de 10 %) pour la charge.
La Heap est stable (bien trop stable par rapport au test exécuté).
En regardant d'un peu plus près l'activité du GC dans la partie de la mémoire appelée Old Generation, on remarque qu'il y a beaucoup trop d'activité.
De même, les temps de réponse ne sont pas extraordinaires.
À ce stade on peut faire un focus sur l'activité du GC qui ne semble pas normale.
II-B. Augmentons la charge en simulant 100 utilisateurs▲
Le taux d'activité GC passe de 10 % à 40 %.
De même le nombre de GC dans la Old Generation augmente fortement.
Les temps de réponse se dégradent fortement.
Sans parler de leur stabilité qui nous conforte dans l'idée qu'il y a un gros problème.
L'utilité d'un test en charge a été clairement démontrée et il devient donc illusoire de passer l'application en production.
II-C. Trouvons la source du problème▲
Afin de détecter si System.gc() est appelé, nous allons instrumenter le bytecode (pratique si l'on n'a pas le code source) de l'application afin qu'il nous l'indique avec le message « System.gc() est appelé » lors de chaque appel.
Bingo, on obtient rapidement la confirmation.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
System.gc() est appelé
Modifions un peu notre script d'instrumentation afin d'avoir la stacktrace lors d'un appel de System.gc(). On obtient :
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.
30.
31.
32.
33.
34.
35.
36.
37.
38.
System.gc() est appelé
StackTrace :
--------------------------------
java.lang.System.gc(System.java)
org.springframework.samples.petclinic.web.FindOwnersForm.processSubmit(FindOwnersForm.java:50)
sun.reflect.GeneratedMethodAccessor82.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:597)
org.springframework.web.bind.annotation.support.HandlerMethodInvoker.doInvokeMethod(HandlerMethodInvoker.java:710)
org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:167)
org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:414)
org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:402)
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:771)
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:716)
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:647)
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:552)
javax.servlet.http.HttpServlet.service(HttpServlet.java:621)
javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:71)
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:240)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:164)
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:462)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:164)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:563)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:399)
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:317)
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:204)
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:311)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
java.lang.Thread.run(Thread.java:662)
La source du problème est détectée dans la fonction : org.springframework.samples.petclinic.web.FindOwnersForm.processSubmit(FindOwnersForm.java:50)
Il ne reste plus qu'à corriger le problème. Pour cela plusieurs solutions sont possibles :
- modifier directement la fonction org.springframework.samples.petclinic.web.FindOwnersForm.processSubmit
- utiliser Findbugs pour détecter les appels à System.gc()
- utiliser l'option -XX:DisableExplicitGC de la JVM
Dans notre cas, nous allons directement corriger le code source, car nous savons exactement où se trouve le problème.
II-D. Relançons nos tests de charge avec 100 utilisateurs▲
Nous pouvons constater la différence et confirmer notre hypothèse.
Le temps de réponse de la transaction fautive est même divisé par dix.
III. Conclusion et remerciements▲
Nous avons vu dans cet article les méfaits de l'utilisation explicite de la méthode System.gc(). Mon conseil en guise de conclusion est de ne pas utiliser de System.gc().
Nous tenons à remercier Pierruel pour sa relecture attentive de cet article et Mickael Baron pour la mise au gabarit.