Je rencontre un problème étrange mais grave en exécutant plusieurs (environ 15) instances d’applications Web Java EE-ish (Hibernate 4 + Spring + Quartz + JSF + Facelets + Richfaces) sur Tomcat 7 / Java 7.

Le système fonctionne correctement, mais après un laps de temps très variable, toutes les instances de l’application subissent simultanément des temps de réponse croissants. Fondamentalement, l’application fonctionne toujours, mais les temps de réponse sont environ trois fois plus élevés.

Ce sont deux diagrammes affichant le temps de réponse de deux workflows / actions courts (connexion, access à la liste des séminaires, ajax-refresh cette liste, déconnexion; la ligne inférieure correspond à la demande de rafraîchissement ajax) de deux exemples d’exemples. de l’application:

• fichier log4j.properties – plusieurs enregistreurs de la même classe
• Comment envoyer correctement un message HTTP au client
• Comment lister les dépendances d’un JAR
• RetentionPolicy CLASS vs RUNTIME
• Java Logging: affiche le numéro de ligne source de l’appelant (pas la méthode d’assistance de journalisation)

Comme vous pouvez voir les deux instances de l’application “exploser” au même moment et restr lent. Après avoir redémarré le serveur, tout est redevenu normal. Toutes les instances de l’application “explosent” simultanément.

Nous stockons les données de session dans une firebase database et les utilisons pour le clustering. Nous avons vérifié la taille et le nombre de sessions et les deux sont plutôt faibles (ce qui signifie que sur d’autres serveurs avec d’autres applications, nous avons parfois des sessions plus grandes et plus nombreuses). L’autre Tomcat dans le cluster rest généralement rapide pendant quelques heures et après cette période aléatoire, il meurt aussi. Nous avons vérifié les tailles de tas avec jconsole et le tas principal rest entre 2,5 et 1 Go, le pool de connexions à la firebase database est essentiellement plein de connexions libres, ainsi que les pools de threads. La taille maximale du tas est de 5 Go, il y a aussi beaucoup d’espace de génération disponible. La charge n’est pas particulièrement élevée; Il y a à peu près 5% de charge sur le processeur principal. Le serveur ne change pas Ce n’est pas non plus un problème matériel puisque nous avons également déployé les applications sur une machine virtuelle où les problèmes restnt les mêmes.

Je ne sais plus où chercher, je suis à court d’idées. Est-ce que quelqu’un a une idée où chercher?

2013-02-21 Mise à jour: nouvelles données!

J’ai ajouté deux autres traces de synchronisation à l’application. En ce qui concerne la mesure: le système de surveillance appelle une servlet qui exécute deux tâches, mesure le temps d’exécution pour chaque serveur et écrit l’heure prise comme réponse. Ces valeurs sont consignées par le système de surveillance.

J’ai plusieurs nouveaux faits intéressants: un redéploiement à chaud de l’application fait que cette instance unique sur le Tomcat actuel est devenue une erreur. Cela semble également affecter les performances de calcul du processeur brut (voir ci-dessous). Cette explosion de contexte individuel est différente de l’explosion du contexte global qui se produit de manière aléatoire.

Maintenant pour certaines données:

Tout d’abord les lignes individuelles:

1. Le bleu clair est le temps d’exécution total d’un petit workflow (détails voir ci-dessus), mesuré sur le client
2. Le rouge est une “partie” de bleu clair et correspond au temps nécessaire pour effectuer une étape spéciale de ce stream de travail, mesurée sur le client.
3. Le bleu foncé est mesuré dans l’application et consiste à lire une liste d’entités de la firebase database via Hibernate et à itérer cette liste, en récupérant des collections paresseuses et des entités paresseuses.
4. Green est un petit benchmark de CPU utilisant des opérations à virgule flottante et à nombre entier. Pour autant que je ne vois pas d’atsortingbution d’object, donc pas de déchets.

Maintenant, pour les différentes étapes de l’explosion: j’ai marqué chaque image avec trois points noirs. Le premier est un “petit” explostion dans plus ou moins une seule application – dans Inst1, il saute (particulièrement visible sur la ligne rouge), tandis que Inst2 ci-dessous rest plus ou moins calme.

Après cette petite explosion, le “big bang” se produit et toutes les instances de l’application sur ce Tomcat explosent (2ème point). Notez que cette explosion affecte toutes les opérations de haut niveau (traitement des demandes, access à la firebase database), mais pas le test du processeur. Il rest bas dans les deux systèmes.

Après cela, j’ai redéployé à chaud Inst1 en touchant le fichier context.xml. Comme je l’ai dit plus tôt, cette instance va de l’explosion à la destruction totale (la ligne bleu clair est hors du tableau – elle est à environ 18 secondes). Notez comment a) ce redéploiement n’affecte pas du tout Inst2 et b) comment l’access à la firebase database brute de Inst1 n’est pas non plus affecté – mais comment le processeur semble soudainement devenir plus lent! . C’est fou, dis-je.

Mise à jour de la mise à jour L’écouteur de prévention des fuites de Tomcat ne dénonce pas les ThreadLocals ou Threads obsolètes lorsque l’application n’est pas déployée. Il semble évidemment y avoir un problème de nettoyage (qui, je suppose, n’est pas directement lié au Big Bang), mais Tomcat n’a aucun indice pour moi.

2013-02-25 Mise à jour: Environnement d’application et calendrier à quartz

L’environnement d’application n’est pas très sophistiqué. Les composants réseau mis à part (je n’en connais pas assez) comportent essentiellement un serveur d’applications (Linux) et deux serveurs de bases de données (MySQL 5 et MSSQL 2008). La charge principale est sur le serveur MSSQL, l’autre sert simplement de lieu de stockage des sessions.

Le serveur d’applications exécute Apache en tant qu’équilibreur de charge entre deux Tomcats. Nous avons donc deux JVM fonctionnant sur le même matériel (deux instances de Tomcat). Nous utilisons cette configuration pour ne pas réellement équilibrer la charge car le serveur d’applications est capable d’exécuter correctement l’application (ce qu’il a fait depuis des années), mais d’activer les petites mises à jour des applications sans interruption. L’application Web en question est déployée en tant que contextes distincts pour différents clients, soit environ 15 contextes par Tomcat. (Il me semble avoir mélangé des “instances” et des “contextes” dans mon message: ici au bureau, ils sont souvent utilisés comme synonymes et nous soaps généralement par magie de quoi parle le collègue. Mon mauvais, je suis vraiment désolé.)

Pour clarifier la situation avec une meilleure formulation : les diagrammes que j’ai affichés montrent les temps de réponse de deux contextes différents de la même application sur la même JVM. Le Big Bang affecte tous les contextes sur une JVM mais ne se produit pas sur l’autre (l’ordre dans lequel les Tomcats explosent est aléatoire). Après le redéploiement à chaud, un contexte sur une instance de Tomcat devient fou (avec tous les effets secondaires amusants, comme un processeur apparemment plus lent pour ce contexte).

La charge globale du système est plutôt faible. Il s’agit d’un logiciel interne d’entreprise avec environ 30 utilisateurs actifs simultanément. Les demandes spécifiques à l’application (touches du serveur) sont actuellement d’environ 130 par minute. Le nombre de demandes uniques est faible, mais les demandes elles-mêmes nécessitent souvent plusieurs centaines de sélections dans la firebase database, ce qui les rend assez onéreuses. Mais généralement, tout est parfaitement acceptable. L’application ne crée pas non plus de grands caches infinis – certaines données de recherche sont mises en cache, mais seulement pour une courte période.

Ci-dessus, j’ai écrit que les serveurs capables d’exécuter l’application fonctionnent bien pendant plusieurs années. Je sais que le meilleur moyen de trouver le problème serait de savoir exactement quand les choses ont mal tourné pour la première fois et de voir ce qui a été changé durant cette période (dans l’application elle-même, les bibliothèques ou l’infrastructure associées). que nous ne soaps pas quand les problèmes se sont produits pour la première fois. Appelons simplement cette sous-évaluation (au sens d’absence) de surveillance des applications …: – /

Nous avons exclu certains aspects, mais l’application a été mise à jour plusieurs fois au cours des derniers mois et nous ne pouvons donc pas simplement déployer une version antérieure. La plus grande mise à jour qui n’a pas été modifiée est le passage de JSP à Facelets. Mais encore, “quelque chose” doit être la cause de tous les problèmes, mais je n’ai aucune idée de la raison pour laquelle Facelets, par exemple, devrait influencer les temps de requête de firebase database purs.

Quartz

En ce qui concerne le calendrier Quartz: il y a un total de 8 emplois. La plupart d’entre eux ne fonctionnent qu’une seule fois par jour et ont à faire avec la synchronisation des données volumineuses (absolument pas “grande” comme dans les “données volumineuses”, c’est juste plus que ce que l’utilisateur moyen voit dans son travail quotidien). Cependant, ces tâches ont bien sûr lieu la nuit et les problèmes surviennent pendant la journée. Je omet une liste détaillée des tâches ici (si cela est bénéfique, je peux bien sûr fournir plus de détails). Le code source des jobs n’a pas été modifié au cours des derniers mois. J’ai déjà vérifié si les explosions étaient alignées sur les tâches – mais les résultats ne sont pas concluants au mieux. Je dirais en fait qu’ils ne sont pas alignés, mais comme il y a plusieurs emplois à chaque minute, je ne peux pas encore les exclure. À mon avis, les tâches acutales qui sont exécutées à chaque minute sont plutôt minces. Elles vérifient généralement si des données sont disponibles (dans différentes sources, bases de données, systèmes externes, compte de messagerie) et écrivent-les dans la firebase database. .

Cependant, je permets actuellement la journalisation de l’exécution des tâches individuelles pour que je puisse voir exactement l’horodatage de début et de fin de chaque exécution de travail. Peut-être cela fournit-il plus de perspicacité.

2013-02-28 Mise à jour: phases et calendrier de JSF

J’ai ajouté manuellement un auditeur de phase JSF à l’application. J’ai exécuté un exemple d’appel (le rafraîchissement ajax) et c’est ce que j’ai (à gauche: instance Tomcat normale, à droite: instance Tomcat après Big Bang – les chiffres ont été pris presque simultanément depuis Tomcats et sont en millisecondes):

1. RESTORE_VIEW: 17 vs 46
2. APPLY_REQUEST_VALUES: 170 vs 486
3. PROCESS_VALIDATIONS: 78 vs 321
4. UPDATE_MODEL_VALUES: 75 vs 307
5. RENDER_RESPONSE: 1059 vs 4162

Le rafraîchissement ajax lui-même appartient à un formulaire de recherche et à son résultat de recherche. Il y a aussi un autre délai entre le filtre de requête le plus externe de l’application et le stream Web qui commence son travail: il y a un FlowExecutionListenerAdapter qui mesure le temps pris dans certaines phases du stream Web. Cet auditeur signale 1405 ms pour “Requête soumise” (ce qui correspond à ce que je sais du premier événement de stream Web) sur un total de 1632 ms pour la requête complète sur un Tomcat non éclaté.
Mais sur le Tomcat éclaté, il indique 5332 ms pour la demande soumise (ce qui signifie que toutes les phases du JSF ont lieu pendant ces 5 secondes) sur une durée totale de 7105ms. .
En dessous de mon filtre de mesure, la chaîne de filtrage contient un org.ajax4jsf.webapp.BaseFilter , puis le servlet Spring est appelé.

2013-06-05 Mise à jour: Tout ce qui se passe ces dernières semaines

Une petite mise à jour plutôt tardive … les performances de l’application sont encore mauvaises après un certain temps et le comportement rest irrégulier. Le profilage n’a pas encore beaucoup aidé, il a simplement généré une énorme quantité de données difficiles à disséquer. (Essayez de fouiller dans les données de performance sur un système de production ou profilez-le… soupir) Nous avons effectué plusieurs tests (extraction de certaines parties du logiciel, suppression du déploiement d’autres applications, etc.). Le mode de vidange par défaut de notre EntityManager est AUTO et pendant l’affichage, beaucoup de récupérations et de sélections sont émises, incluant toujours la vérification si le vidage est nécessaire.
Nous avons donc construit un programme d’écoute de phase JSF qui définit le mode de RENDER_RESPONSE sur COMMIT pendant RENDER_RESPONSE . Cela a beaucoup amélioré la performance globale et semble avoir quelque peu atténué les problèmes.

Cependant, la surveillance de nos applications continue à produire des résultats et des performances complètement insensés dans certains contextes sur certaines instances de Tomcat. Comme une action qui devrait se terminer en moins d’une seconde (et qui le fait après le déploiement) et qui prend maintenant plus de quatre secondes. (Ces nombres sont pris en charge par le chronométrage manuel dans les navigateurs, ce n’est donc pas la surveillance qui pose problème).

Voir l’image suivante par exemple:

Ce diagramme montre deux instances de tomcat exécutant le même contexte (c’est-à-dire même firebase database, même configuration, même jar). Encore une fois, la ligne bleue représente la quantité de temps nécessaire pour effectuer des opérations de lecture de firebase database (extraire une liste d’entités, les parcourir, récupérer des collections et des données associées). Les lignes turquoise et rouge sont mesurées en rendant plusieurs vues et en effectuant un rafraîchissement ajax, respectivement. Les données rendues par deux des requêtes en turquoise-ish et en rouge sont essentiellement les mêmes que celles demandées pour la ligne bleue.

Maintenant, vers 0700 sur l’instance 1 (à droite), il y a cette augmentation énorme du temps de firebase database qui semble affecter les temps de réponse de rendu, mais uniquement sur tomcat 1. Tomcat 0 n’est pas affecté par ce problème. serveur ou réseau avec les deux tomcats fonctionnant sur le même matériel physique. Cela doit être un problème de logiciel dans le domaine Java.

Lors de mes derniers tests, j’ai trouvé quelque chose d’intéressant: toutes les réponses contiennent l’en-tête “X-Powered-By: JSF / 1.2, JSF / 1.2”. Certains (les réponses de redirection produites par WebFlow) ont même trois fois “JSF / 1.2”.
J’ai tracé les parties de code qui définissent ces en-têtes et la première fois que cet en-tête est défini, il est causé par cette stack:

 ... at org.ajax4jsf.webapp.FilterServletResponseWrapper.addHeader(FilterServletResponseWrapper.java:384) at com.sun.faces.context.ExternalContextImpl.(ExternalContextImpl.java:131) at com.sun.faces.context.FacesContextFactoryImpl.getFacesContext(FacesContextFactoryImpl.java:108) at org.springframework.faces.webflow.FlowFacesContext.newInstance(FlowFacesContext.java:81) at org.springframework.faces.webflow.FlowFacesContextLifecycleListener.requestSubmitted(FlowFacesContextLifecycleListener.java:37) at org.springframework.webflow.engine.impl.FlowExecutionListeners.fireRequestSubmitted(FlowExecutionListeners.java:89) at org.springframework.webflow.engine.impl.FlowExecutionImpl.resume(FlowExecutionImpl.java:255) at org.springframework.webflow.executor.FlowExecutorImpl.resumeExecution(FlowExecutorImpl.java:169) at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:183) at org.springframework.webflow.mvc.servlet.FlowController.handleRequest(FlowController.java:174) at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:920) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:827) at javax.servlet.http.HttpServlet.service(HttpServlet.java:641) ... several thousands ;) more 

La deuxième fois que cet en-tête est défini par

 at org.ajax4jsf.webapp.FilterServletResponseWrapper.addHeader(FilterServletResponseWrapper.java:384) at com.sun.faces.context.ExternalContextImpl.(ExternalContextImpl.java:131) at com.sun.faces.context.FacesContextFactoryImpl.getFacesContext(FacesContextFactoryImpl.java:108) at org.springframework.faces.webflow.FacesContextHelper.getFacesContext(FacesContextHelper.java:46) at org.springframework.faces.richfaces.RichFacesAjaxHandler.isAjaxRequestInternal(RichFacesAjaxHandler.java:55) at org.springframework.js.ajax.AbstractAjaxHandler.isAjaxRequest(AbstractAjaxHandler.java:19) at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.createServletExternalContext(FlowHandlerAdapter.java:216) at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:182) at org.springframework.webflow.mvc.servlet.FlowController.handleRequest(FlowController.java:174) at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:920) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:827) at javax.servlet.http.HttpServlet.service(HttpServlet.java:641) 

Je n’ai aucune idée si cela pourrait indiquer un problème, mais je ne l’ai pas remarqué avec d’autres applications qui s’exécutent sur l’un de nos serveurs. Je n’ai vraiment aucune idée de ce que fait le code du cadre (certes, je ne l’ai pas encore plongé) … peut-être que quelqu’un a une idée? Ou est-ce que je cours dans une impasse?

annexe

Mon code de test de processeur se compose d’une boucle qui calcule Math.tan et utilise la valeur du résultat pour modifier certains champs de l’instance de la servlet (aucun volatile / synchronisé) et effectue ensuite plusieurs calculs bruts d’entiers. Ce n’est pas sévèrement sophistiqué, je sais, mais bon … ça semble montrer quelque chose dans les charts, mais je ne suis pas sûr de ce que ça montre. Je fais les mises à jour sur le terrain pour empêcher HotSpot d’optimiser tout mon précieux code;)

  long time2 = System.nanoTime(); for (int i = 0; i < 5000000; i++) { double tan = Math.tan(i); if (tan < 0) { this.l1++; } else { this.l2++; } } for (int i = 1; i < 7500; i++) { int n = i; while (n != 1) { this.steps++; if (n % 2 == 0) { n /= 2; } else { n = n * 3 + 1; } } } // This execution time is written to the client. time2 = System.nanoTime() - time2; 

• Initialisation du bean Spring à partir d’une méthode statique d’une autre classe?
• Comment gérer les cookies avec HttpClient sous Android et / ou Java?
• Objectif de l’option «Construire automatiquement» dans éclipse
• Bauerca drag-sort-listview exemple simple
• Qu’est-ce qu’une opération «escape-hatch» dans un stream Java?

 -XX:ReservedCodeCacheSize=256m 

 jstat -gcutil  1000 100 

 -XX:+UseConcMarkSweepGC