tomee-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Romain Manni-Bucau <rmannibu...@gmail.com>
Subject Re: EJB class loaded twice, causes 2 file handles for logging
Date Wed, 22 Nov 2017 13:10:11 GMT
Hi

this is normal since the classes will be loaded during scanning with a
temp classloader and then with the runtime classloader.

Generally a good pattern in EE is to not have static variables to
avoid that pitfall.

A general fix is to configure the logging framework to close the
handlers/appenders with the classloader destruction (or equivalent) or
create them lazily when the first record is emitted.


2017-11-22 13:06 GMT+01:00 Robert . <robert.discussions@gmail.com>:
> I'm using logback in my enterprise application, including an EJB bean.
> The EJB bean has a sl4j logger, and I bundle the logback library in the ear.
> The problem I'm having is that after startup on Windows Server there are 2
> file handles to my
> logback created application log. This creates some problems if I want to
> have some rolling policy on my logging that
> requires renames.
>
> I tried to debug who is opening the same file twice. I noticed the EJB bean
> is loaded twice, which causes the
> logger to be initialized twice, and the file opened twice.
>
> Has anyone else had problems with multiple file handles on log files on
> TomEE? Is there some way to prevent this?
>
> I'm using Apache TomEE Plus 7.0.2
>
> You can see here two parts of stacktraces where this happens.
>
> First load EJB
>       at org.apache.openejb.util.Classes.forName(Classes.java:64)
>       at
> org.apache.openejb.config.rules.ValidationBase.loadClass(ValidationBase.java:151)
>       at
> org.apache.openejb.config.rules.CheckMethods.check_remoteInterfaceMethods(CheckMethods.java:137)
>       at
> org.apache.openejb.config.rules.CheckMethods.validate(CheckMethods.java:47)
>       at
> org.apache.openejb.config.rules.ValidationBase.validate(ValidationBase.java:50)
>       at
> org.apache.openejb.config.AppValidator.validate(AppValidator.java:102)
>       at
> org.apache.openejb.config.ValidateModules.deploy(ValidateModules.java:38)
>       at
> org.apache.openejb.config.ConfigurationFactory$Chain.deploy(ConfigurationFactory.java:420)
>       at
> org.apache.openejb.config.ConfigurationFactory.configureApplication(ConfigurationFactory.java:1037)
>       at
> org.apache.openejb.config.ConfigurationFactory.configureApplication(ConfigurationFactory.java:856)
>       at
> org.apache.openejb.config.ConfigurationFactory.getOpenEjbConfiguration(ConfigurationFactory.java:547)
>       at
> org.apache.openejb.config.ConfigurationFactory.getOpenEjbConfiguration(ConfigurationFactory.java:634)
>       at
> org.apache.openejb.assembler.classic.Assembler.getOpenEjbConfiguration(Assembler.java:503)
>       at
> org.apache.openejb.assembler.classic.Assembler.build(Assembler.java:482)
>
> Second load EJB
>       at java.lang.Class.forName(Class.java:278)
>       at
> org.apache.openejb.assembler.classic.EnterpriseBeanBuilder.load(EnterpriseBeanBuilder.java:428)
>       at
> org.apache.openejb.assembler.classic.EnterpriseBeanBuilder.loadClass(EnterpriseBeanBuilder.java:404)
>       at
> org.apache.openejb.assembler.classic.EnterpriseBeanBuilder.build(EnterpriseBeanBuilder.java:81)
>       at
> org.apache.openejb.assembler.classic.EjbJarBuilder.build(EjbJarBuilder.java:68)
>       at
> org.apache.openejb.assembler.classic.Assembler.initEjbs(Assembler.java:1411)
>       at
> org.apache.openejb.assembler.classic.Assembler.createApplication(Assembler.java:904)
>       at
> org.apache.openejb.assembler.classic.Assembler.createApplication(Assembler.java:717)
>       at
> org.apache.openejb.assembler.classic.Assembler.buildContainerSystem(Assembler.java:595)
>       at
> org.apache.openejb.assembler.classic.Assembler.build(Assembler.java:483)
>
>
> I tried to reproduce the same problem in a normal Java application that
> uses slf4j and logback by loading
> the same class twice. Even though this also causes 2 FileOutputStreams on
> the same file to be created, I do not have
> 2 file handles after that, but only 1. That made me curious on when a new
> file handle is actually created by the JVM.
> I tried to look on information about this but I could not find anything.
>
> Here is part of the stacktrace that initializes logback from slf4j.
>
>       at ch.qos.logback.core.FileAppender.openFile(FileAppender.java:186)
>       at ch.qos.logback.core.FileAppender.start(FileAppender.java:121)
>       at
> ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:99)
>       at
> ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:90)
>       at
> ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:309)
>       at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:193)
>       at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:179)
>       at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
>       at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:155)
>       - locked <0x10b1> (a ch.qos.logback.core.spi.LogbackLock)
>       at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:142)
>       at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:103)
>       at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
>       at
> ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
>       at
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150)
>       at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)

Mime
View raw message