Mais outro Blog sobre SOA, TI, Java e bobagens...

17 de nov. de 2008

JSF logging no JBoss

Esta semana em um teste de carga de uma aplicacao JSF/JBoss Seam rodando no JBoss 4.3 EAP reparei um grande número de threads com estado "waiting to lock" na classe Logger e enfileiradas, em sua maioria no seguinte stack...

java.util.logging.Logger.findResourceBundle(Logger.java:1252)
java.util.logging.Logger.doLog(Logger.java:492)
java.util.logging.Logger.log(Logger.java:517)
com.sun.faces.util.Util.getFacesMapping(Util.java:628)
com.sun.faces.application.ViewHandlerImpl.getActionURL(ViewHandlerImpl.java:663)
org.jboss.seam.jsf.SeamViewHandler.getActionURL(SeamViewHandler.java:74)
com.sun.facelets.FaceletViewHandler.getActionURL(FaceletViewHandler.java:803)
org.ajax4jsf.application.ViewHandlerWrapper.getActionURL(ViewHandlerWrapper.java:92)
com.sun.faces.renderkit.html_basic.FormRenderer.getActionStr(FormRenderer.java:195)
com.sun.faces.renderkit.html_basic.FormRenderer.encodeBegin(FormRenderer.java:127)
javax.faces.component.UIComponentBase.encodeBegin(UIComponentBase.java:813)
javax.faces.component.UIComponent.encodeAll(UIComponent.java:928)
javax.faces.component.UIComponent.encodeAll(UIComponent.java:933)
javax.faces.component.UIComponent.encodeAll(UIComponent.java:933)
com.sun.facelets.FaceletViewHandler.renderView(FaceletViewHandler.java:592)
org.ajax4jsf.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:108)
org.ajax4jsf.application.AjaxViewHandler.renderView(AjaxViewHandler.java:196)
com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:110)
com.sun.faces.lifecycle.Phase.doPhase(Phase.java:100)
com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
javax.faces.webapp.FacesServlet.service(FacesServlet.java:266)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:83)
org.jboss.seam.web.IdentityFilter.doFilter(IdentityFilter.java:38)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
org.jboss.seam.web.MultipartFilter.doFilter(MultipartFilter.java:90)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
org.jboss.seam.web.ExceptionFilter.doFilter(ExceptionFilter.java:64)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
org.jboss.seam.web.RedirectFilter.doFilter(RedirectFilter.java:45)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
org.ajax4jsf.webapp.BaseXMLFilter.doXmlFilter(BaseXMLFilter.java:177)
org.ajax4jsf.webapp.BaseFilter.handleRequest(BaseFilter.java:267)
org.ajax4jsf.webapp.BaseFilter.processUploadsAndHandleRequest(BaseFilter.java:380)
org.ajax4jsf.webapp.BaseFilter.doFilter(BaseFilter.java:507)
org.jboss.seam.web.Ajax4jsfFilter.doFilter(Ajax4jsfFilter.java:56)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
org.jboss.seam.web.LoggingFilter.doFilter(LoggingFilter.java:58)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:73)
org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:73)
org.jboss.seam.servlet.SeamFilter.doFilter(SeamFilter.java:158)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:433)
org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:241)
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:580)
org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
java.lang.Thread.run(Thread.java:619)

Bom sendo bastante objetivo, se observarem na implementacao JSF perceberão a existencia de diversas chamadas de Logger.log(...), o problema em si não é esse mas o fato que para cada chamada dessa temos um isDebugEnabled(...) associado (ou algo similar... não me recordo agora) e isDebugEnabled, no meu caso, sempre estava dando true. Embora meu root logger no jboss-log4j estivesse configurado para nível ERROR, eu não tinha um category específico para o JSF e aparentemente isso levava a DEBUG ser o nível default. Declarar um category no jboss-log4j para o JSF e Facelets é algo natural nas versões JBoss 4.2/4.3 EAP, ou seja, embora JSF utilize java.util.logging, o JBoss é capaz de interceptar os loggers on-the-fly e envia-los para o log4j do container, contudo minha percepcão é, na dúvida garanta que o nível de log do JSF e do Facelets estão corretamente configurados declarando-os no arquivo jboss-log4j.xml. Declara-los explicitamente como ERROR/WARN, no meu caso, resolveu meus problemas de lock no Logger.

Seguem os nomes dos loggers:

javax.enterprise.resource.webcontainer.jsf.managedbean
javax.enterprise.resource.webcontainer.jsf.renderkit
javax.enterprise.resource.webcontainer.jsf.taglib
javax.enterprise.resource.webcontainer.jsf.application
javax.enterprise.resource.webcontainer.jsf.context
javax.enterprise.resource.webcontainer.jsf.config
javax.enterprise.resource.webcontainer.jsf.lifecycle
javax.enterprise.resource.webcontainer.jsf.timing
facelets.compiler
facelets.factory
facelets.tag.component
facelets.viewhandler
facelets.tag.meta

Mais Informacões:

http://www.jboss.org/community/docs/DOC-10379

Nenhum comentário: