Acces à la base bloquer

Bonjour,

c'est un problème que j'ai depuis au moins 2 mois sur une application sur TOMCAT. le serveur tourne et au bout d'un temps X (entre 10 minutes et 10 jours) l'accès à la base (Mysql 5.0) via Hibernate (3.2.6) est bloqué. Pas de log d'erreur.
Donc j'ai ajouté des loggers et j'ai finit par trouver que le code bloquait sur les fonction "list" et sur tout les accès vers la base en général.
En utilisant Your kit Profiler j'ai pus trouver la pile d'appel et surtout ou les accés bloquaient :aie:

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

http-0.0.0.0-80-7 [BLOCKED] CPU time: 0:00 ch.qos.logback.classic.Logger.callAppenders(LoggingEvent) ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(String, Marker, Level, String, Object[], Throwable) ch.qos.logback.classic.Logger.filterAndLog(String, Marker, Level, String, Object[], Throwable) ch.qos.logback.classic.Logger.log(Marker, String, int, String, Throwable) org.apache.commons.logging.impl.SLF4JLocationAwareLog.debug(Object) org.hibernate.jdbc.AbstractBatcher.logOpenPreparedStatement() org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(String, boolean, ScrollMode) org.hibernate.loader.Loader.prepareQueryStatement(QueryParameters, boolean, SessionImplementor) org.hibernate.loader.Loader.doQuery(SessionImplementor, QueryParameters, boolean) org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(SessionImplementor, QueryParameters, boolean) org.hibernate.loader.Loader.doList(SessionImplementor, QueryParameters) org.hibernate.loader.Loader.listIgnoreQueryCache(SessionImplementor, QueryParameters) org.hibernate.loader.Loader.list(SessionImplementor, QueryParameters, Set, Type[]) org.hibernate.loader.criteria.CriteriaLoader.list(SessionImplementor) org.hibernate.impl.SessionImpl.list(CriteriaImpl) org.hibernate.impl.CriteriaImpl.list() ...connector.hibernate.HibernateUtil.list(Criteria) ...connector.user.UserHibernateFactory.exist(String, String) ...manager.DomainUserManagerImpl.authenticateUser(String, String, String, boolean) ...domain.Authenticate.<init>(String, String, String, boolean) org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ...servlet.filter.SetCharacterEncodingFilter.doFilter(ServletRequest, ServletResponse, FilterChain) java.lang.Thread.run()

---

Voila c'est donc bloque sur ch.qos.logback.classic.Logger.callAppenders.
S'il vous plait, Quelqu'un a t'il une vague idée sur le sujet, je prend toutes les suggestions.
J'ai plusieurs piste mais rien jusque là n'a pus contrecarrer ce bug et je ne parviens pas à le provoquer.

Si les accès sont bloqués, donc en attente de la BDD, il devrait bien y avoir un timeout sur la gestion des transactions et donc un message d'erreur. Sinon, rien dans les logs MySQL ?

visiblement, c'est ce ch.qos.logback qui foire, je sais pas ce que c'est que ce truc, mais je propose de le virer pour tester? :)

Merci beaucoup pour vos suggestions.
il a 3 jours J'ai téléchargé les sources de logback et supprimé le code contenu dans la méthode callAppender.

Code:

---

ch.qos.logback.classic.Logger.callAppenders

---

Malheureusement cela supprime la log d'hibernate.
J'ai trouvé un obscure bug de DEADLOCK sur multicore qui pouvait exister sur cette librairie. (pour info le BUG pour ma part c'est produit en utilisant la 0.9.8 et j'ai recodé la 0.9.9)
http://bugzilla.qos.ch/show_bug.cgi?id=112.
Le problème est que je ne suis pas parvenu a reproduire ce BUG. J'ai par contre "réussi" à trouver un autre BUG sur CriteriaLoader.list avec un BUG déjà plus connu sur C3P0 qui fait APPARENT DEADLOCK. Ceci dit ce bug n'est pas apparut lors de l'exploitation du serveur mais seulement dans les tests de stress système et il a disparu avec utilisant la config de ce lien http://www.mchange.com/projects/c3p0/index.html par contre en utilisant celle de la doc d'hibernate http://www.hibernate.org/214.html le deadlock ce produit.
Pour le moment, les modifications ont été effectué et le BUG n'est pas réapparu. pas de blocage de l'accès.
Pour l'instant je demeure dans les hypothèses.

J'étais tellement persuadé que le problème venait d'un code Java que j'ai même pas pensé à regarder la log de Mysql ce qui est un oubli grossier. Cependant les Accés à Mysql (Via Mysql Browser) fonctionnaient et fonctionne toujours très bien que l'accès Java soit bloqué.

Voila je ne suis pas sur à 100% d'avoir corrigé mon problème mais j'espère que ce message aidera quelqu'un d'autre à corriger les siens.

Une idée qui m'est venu comme ça :
Ça ne viendrait pas d'un problème d'espace mémoire....

Tu veux dire un problème de type "out of memory" ?
En tous cas il n y en pas de trace de ce type. Je me suis aussi posé la question sur le la limitation du nombre de Thread mais d'après YJP la mémoire utilisée est faible et le nombre de Thread est inférieure à 60. Ceci dit l'application a déjà plantée sans que j'ai une quelconque information via YJP (YourKit Java Profiler) ou via la log de base donc rien n'est à exclure.

vu que, d'après ton trace, tu "bloque" dans tes loggers suisses, je suggèrerait de les virer complètement de l'application pour voir. Ils sont peut etre mal codé, gèrent mal la concurrence et donc, quand hiberante fait deux logs simultanés sur deux threads parallèlles, le logger se met en deadlock....?

Le problème c'est qu hibernate ne veut pas démarrer sans la lib logback, j'ai donc supprimé les code avec les synchronize dans callappender qui provoque un des deadlocks. problèmes plus de trace avec Hibernate ce qui me parasite pour les autres erreurs (Exemple : l'erreur Apparent Deadlock). Etant donnée la gravité du problème du DEADLOCK avec logback je tourne actuellement sans l'affichage de la log.

heuuu, met log4j en attendant? L'est déjà plus connu que logback :D Vu que hibernate utilise commons-logging, il a pas besoin de logback, juste d'un logger reconnu par commons-logging.

Merci pour tes précieux avis.

Voila plus en détails ma situation : :
J'ai déjà Log4J de configurer mais je ne suis pas parvenu à forcer Hibernate à l'utiliser dans le WAR. En fait logback est utiliser aussi par une autre Appli du mon WAR (RED5) et c'est elle qui bloque le démarrage si logback n'est pas présent :bug:, donc pour palier à toutes mauvaise surprise j'ai voulu ajouter des traces lors des appels de logback pour voir ou était tout les appels.

Quand je code des tests dans la sandbox avec Eclipse pour hibernate j'utilise Log4J et j'ai bien la Log mais la je sais pas pourquoi c'est logback qui est appelé quand je suis dans le WAR avec Tomcat.
J'ai pas trouver dans mon Hibernate.cfg.xml comment forcer tel ou tel API de log. Si tu as un lien vers une doc sur le sujet je suis preneur.

ha mon avis ton autre framework force logback dans commons logging, du coup commons logging utilise logback pour toute la webapp (youpie hein!)

Je confirme YOUPI :aie:,
du coup j'ai orienté mes recherches sur apache commons logging, sur Google pour forcer à mon tour l'utilisation de Log4J pour hibernate pour essayer de retrouver les logs. Pour l'instant j'ai rien trouver.
Merci encore, j'y vois déjà plus clair sur le problème.