Le Blog des Experts en Performance Informatique

Pourquoi il est dangereux d’utiliser System.gc()

En java, la gestion de la mémoire est réalisée par la JVM, en particulier par le Garbage Collector (ramasse miettes). Or, si l'on regarde d'un peu plus près, on remarque que l'on peut appeler le GC par l'instruction System.gc().
On se dit que cela pourrait être utile afin de libérer un maximum de mémoire avant certains traitements. Cette démarche est fortement déconseillé car c'est une "fausse bonne idée" comme nous allons le démontrer par la suite.

1. Un Peu de théorie

Regardons la Javadoc.

    /**
     * Runs the garbage collector.
     * <p>
     * Calling the <code>gc</code> 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.
     * <p>
     * The call <code>System.gc()</code> is effectively equivalent to the
     * call:
     * Runtime.getRuntime().gc()
     *
     * @see     java.lang.Runtime#gc()
     */

 

Première mauvaise nouvelle, System.gc() ne réalise pas forcement un GC (il peut ne rien faire) et surtout on se 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 forcement 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).

2. 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é.

 

2.1 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.

A ce stade on peut faire un focus sur l'activité du GC ne semble pas normale.

 

2.2 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 leurs stabilités qui nous confortent dans l'idée qu'il y a un gros problème.

En plus de montrer l'utilité d'un test de charge, toute illusion de passer l'application en production s'évapore.

2.3 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.

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.

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.

2.4 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.

3. Mon conseil

Mon conseil est de ne pas utiliser de System.gc().

Laisser un commentaire

Mots-clés
RSS Feed
Share on TwitterSubmit to reddit