Discussion:
Binding takes for ages on Jonas-server. No additional info to troubleshoot
Stefaan Somers
2011-08-18 11:18:16 UTC
Permalink
Hi,

we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.

18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms


Greetings,

Stefaan Somers
Guillaume Sauthier (OW2)
2011-08-18 11:26:46 UTC
Permalink
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Stefaan Somers
2011-08-18 13:50:42 UTC
Permalink
Hi,

I included the following line in trace.properties, but I see no
additional logging :
logger.org.ow2.easybeans DEBUG

Greetings

On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Guillaume Sauthier (OW2)
2011-08-18 13:57:06 UTC
Permalink
the format is:
logger.<name>.level <level>

you missed the .level

--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Stefaan Somers
2011-08-18 14:14:53 UTC
Permalink
No luck either.

I hereby include the content of the trace.properties :


# -----------------------------------------------------------------------
# This is a default configuration file for monolog.
#
# 2 handlers have been defined : tty (System.out) and logf (file)
#
# Patterns for each handler may include these possible values :
# %h the thread name
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file.
# Each logger inherits from its parent for properties not defined.
# The root logger is "root". It must always be defined.
#
# Each logger is associated with a level that can be one of :
# ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
#
# -> More info on http://www.objectweb.org/monolog/doc.html
# -----------------------------------------------------------------------

# -----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
# -----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory
# log.config.classname org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory

# -----------------------------------------------------------------------
# tty : console handler
# The switch attribute is used to log either on System.out or System.err
# depending of the level of the log.
# -----------------------------------------------------------------------
handler.tty.type Console
handler.tty.output Switch
handler.tty.pattern %d : %O{1}.%M : %m%n

# -----------------------------------------------------------------------
# mesonly : console handler without header
# -----------------------------------------------------------------------
handler.mesonly.type Console
handler.mesonly.output Switch
handler.mesonly.pattern %m%n

# -----------------------------------------------------------------------
# logf : file handler
# -----------------------------------------------------------------------
#handler.logf.type File
#handler.logf.output automatic
#handler.logf.pattern %d : %l : %h : %O{1}.%M : %m%n

# -----------------------------------------------------------------------
# wsdl : file handler
# -----------------------------------------------------------------------
handler.wsdl.type File
handler.wsdl.output jonas_wsdls.log
handler.wsdl.pattern %d : %l : %h : %O{1}.%M : %m%n

# -----------------------------------------------------------------------
# jmxHandler : jmx handler
# -----------------------------------------------------------------------
#handler.jmxHandler.type jmx
#handler.jmxHandler.output Switch
#handler.jmxHandler.pattern %d : %l : %h : %O{1}.%M : %m%n


# -----------------------------------------------------------------------
# logf : rolling file handler
# -----------------------------------------------------------------------
handler.logf.type RollingFile
handler.logf.output jonas_ns.log
handler.logf.pattern %d : %l : %h : %O{1}.%M : %m%n
#handler.logf.fileNumber 2
#handler.logf.maxSize 10000
handler.logf.fileNumber 10
handler.logf.maxSize 10485760

# -----------------------------------------------------------------------
# logger definitions
# -----------------------------------------------------------------------
#logger.root.handler.0 tty
#logger.root.handler.1 logf
#logger.root.handler.2 jmxHandler
logger.root.handler.0 logf
logger.root.handler.1 tty

logger.root.level INFO
logger.org.ow2.level INFO
logger.org.objectweb.level INFO

#-----------------------------------------------------------------------
# JOnAS logger definitions
#-----------------------------------------------------------------------

logger.org.ow2.jonas.admin.level INHERIT

logger.org.ow2.jonas.bootstrap.level INHERIT

logger.org.ow2.jonas.client.level INHERIT

logger.org.ow2.jonas.cluster.daemon.level INHERIT

logger.org.ow2.jonas.cmd.level INHERIT

logger.org.ow2.jonas.cmi.level INHERIT

logger.org.ow2.jonas.ha.level INHERIT

logger.org.ow2.jonas.db.level INHERIT

logger.org.ow2.jonas.dbm.level INHERIT
logger.org.ow2.jonas.dbm.con.level INHERIT
logger.org.ow2.jonas.dbm.ps.level INHERIT
logger.org.ow2.jonas.dbm.xa.level INHERIT

logger.org.ow2.jonas.deployment.level INHERIT
logger.org.ow2.jonas.deployablemonitor.level INHERIT
logger.org.ow2.jonas.deployment.client.level INHERIT
logger.org.ow2.jonas.deployment.domain.level INHERIT
logger.org.ow2.jonas.deployment.ejb.level INHERIT
logger.org.ow2.jonas.deployment.ejb.digester.level FATAL



logger.org.ow2.jonas.domain.management.level INHERIT

logger.org.ow2.jonas.ear.level INHERIT

logger.org.ow2.jonas.ee.level INHERIT
logger.org.ow2.jonas.ee.jdbc.level INHERIT
logger.org.ow2.jonas.ee.jdbc.RA.level INHERIT
logger.org.ow2.jonas.ee.jdbc.sql.level INHERIT
logger.org.ow2.jonas.ee.jdbc.xa.level INHERIT

logger.org.ow2.jonas.ejb.level INHERIT

#logger.org.ow2.jonas.generators.handler.0 mesonly
#logger.org.ow2.jonas.generators.additivity false

logger.org.ow2.jonas.generators.genbase.level INHERIT
logger.org.ow2.jonas.generators.genclientstub.level INHERIT
logger.org.ow2.jonas.generators.genic.level INHERIT
logger.org.ow2.jonas.generators.genic.velocity.level ERROR
logger.org.ow2.jonas.generators.wsgen.level INHERIT
logger.org.ow2.jonas.generators.wsgen.ews.level INHERIT

logger.org.ow2.jonas.jca.level INHERIT
logger.org.ow2.jonas.jca.connection.level INHERIT
logger.org.ow2.jonas.jca.management.level INHERIT
logger.org.ow2.jonas.jca.pool.level INHERIT
logger.org.ow2.jonas.jca.process.level INHERIT
logger.org.ow2.jonas.jca.setters.level INHERIT

logger.org.ow2.jonas.jmx.level INHERIT

logger.org.ow2.jonas.lib.ejb21.level INHERIT
logger.org.ow2.jonas.lib.ejb21.coherence.level INHERIT
logger.org.ow2.jonas.lib.ejb21.context.level INHERIT
logger.org.ow2.jonas.lib.ejb21.dd.level INHERIT
logger.org.ow2.jonas.lib.ejb21.endpoint.level INHERIT
logger.org.ow2.jonas.lib.ejb21.factory.level INHERIT
logger.org.ow2.jonas.lib.ejb21.genclass.level INHERIT
logger.org.ow2.jonas.lib.ejb21.interp.level INHERIT
logger.org.ow2.jonas.lib.ejb21.mdb.level INHERIT
logger.org.ow2.jonas.lib.ejb21.mijorm.level INHERIT
logger.org.ow2.jonas.lib.ejb21.query.level INHERIT
logger.org.ow2.jonas.lib.ejb21.security.level INHERIT
logger.org.ow2.jonas.lib.ejb21.ssfpool.level INHERIT
logger.org.ow2.jonas.lib.ejb21.swapper.level INHERIT
logger.org.ow2.jonas.lib.ejb21.synchro.level INHERIT
logger.org.ow2.jonas.lib.ejb21.thread.level INHERIT
logger.org.ow2.jonas.lib.ejb21.tx.level INHERIT
logger.org.ow2.jonas.lib.ejb21.ha.level INHERIT
logger.org.ow2.jonas.lib.ejb21.ha.interceptors.iiop.level INHERIT
logger.org.ow2.jonas.lib.ejb21.ha.interceptors.jrmp.level INHERIT


logger.org.ow2.jonas.lib.jms.level INHERIT

logger.org.ow2.jonas.lib.naming.java.level INHERIT

logger.org.ow2.jonas.lib.svc.level INHERIT

logger.org.ow2.jonas.lib.timer.level INHERIT

logger.org.ow2.jonas.lib.util.level INHERIT

logger.org.ow2.jonas.lib.windows.level INHERIT

logger.org.ow2.jonas.lib.work.level INHERIT

logger.org.ow2.jonas.loader.level INHERIT

logger.org.ow2.jonas.mail.level INHERIT

logger.org.ow2.jonas.management.level INHERIT
logger.org.ow2.jonas.management.cluster.level INHERIT
logger.org.ow2.jonas.management.domain.level INHERIT
logger.org.ow2.jonas.management.event.level INHERIT
logger.org.ow2.jonas.management.j2eemanagement.level INHERIT
logger.org.ow2.jonas.management.j2eemanagement.event.level INHERIT

logger.org.ow2.jonas.naming.level INHERIT

logger.org.ow2.jonas.propagation.level INHERIT

logger.org.ow2.jonas.publication.handler.0 wsdl
logger.org.ow2.jonas.publication.additivity false

logger.org.ow2.jonas.registry.level INHERIT

logger.org.ow2.jonas.security.level INHERIT
logger.org.ow2.jonas.security.csiv2.level INHERIT
logger.org.ow2.jonas.security.csiv2_details.level INHERIT
logger.org.ow2.jonas.security.jacc.level INHERIT
logger.org.ow2.jonas.security.ws.level INHERIT

logger.org.ow2.jonas.server.level INHERIT

logger.org.ow2.jonas.web.level INHERIT

logger.org.ow2.jonas.webapp.jadmin.servlet.level INHERIT

logger.org.ow2.jonas.work.level INHERIT

logger.org.ow2.jonas.workcleaner.level INHERIT

logger.org.ow2.jonas.ws.level INHERIT
logger.org.ow2.jonas.ws.wsdl.level INHERIT



#-------
# JOTM
#-------
logger.org.objectweb.jotm.level INFO
logger.org.objectweb.jotm.jta.level INHERIT
logger.org.objectweb.jotm.tm.level INHERIT
logger.org.objectweb.jotm.recovery.level INHERIT

#-------
# MEJB
#-------
logger.org.ow2.jonas.ee.mejb.level INFO

#-------
# CAROL
#-------
logger.org.ow2.carol.level INFO
logger.org.ow2.carol.rmi.level INHERIT
logger.org.ow2.carol.jndi.level INHERIT

#-------
# JORM
#-------
logger.org.objectweb.jorm.level WARN
logger.org.objectweb.jorm.compiler.level INHERIT
logger.org.objectweb.jorm.xml2mi.level INHERIT
logger.org.objectweb.jorm.mi2xml.level INHERIT
logger.org.objectweb.jorm.metainfo.level INHERIT
logger.org.objectweb.jorm.generator.level INHERIT
logger.org.objectweb.jorm.generator.velocity.level ERROR
logger.org.objectweb.jorm.mapper.rdb.generator.level INHERIT

#-------
# MEDOR
#-------
logger.org.objectweb.medor.level INHERIT
logger.org.objectweb.medor.optim.rule.level INHERIT
logger.org.objectweb.medor.optim.rewriter.level INHERIT
logger.org.objectweb.medor.eval.rdb.level INHERIT

#-------
# JORAM
#-------
logger.fr.dyade.aaa.level ERROR
logger.fr.dyade.aaa.agent.level ERROR
logger.fr.dyade.aaa.agent.Agent.level INHERIT
logger.fr.dyade.aaa.agent.Engine.level INHERIT
logger.fr.dyade.aaa.agent.Service.level INHERIT
logger.org.objectweb.joram.level ERROR
logger.org.objectweb.joram.mom.level INHERIT
logger.org.objectweb.joram.mom.Destination.level INHERIT
logger.org.objectweb.joram.mom.Proxy.level INHERIT
logger.org.objectweb.joram.client.level INHERIT
logger.org.objectweb.joram.client.jms.Client.level ERROR
logger.org.objectweb.joram.client.connector.Adapter.level ERROR

#-------
# SPEEDO
#-------
logger.org.objectweb.speedo.level WARN
## GENERATION
logger.org.objectweb.speedo.generation.SpeedoCompiler.level INFO
## RUN TIME
logger.org.objectweb.speedo.init.level INHERIT
logger.org.objectweb.speedo.po-manager-factory.level INHERIT
logger.org.objectweb.speedo.po-manager-switch.level INHERIT
logger.org.objectweb.speedo.po-manager-pool.level INHERIT
logger.org.objectweb.speedo.po-manager-instanciator.level INHERIT
logger.org.objectweb.speedo.po-manager.level INHERIT
logger.org.objectweb.speedo.po-manager.query.level INHERIT
logger.org.objectweb.speedo.mapper.level INHERIT
logger.org.objectweb.speedo.mapper.mapper.level INHERIT
logger.org.objectweb.speedo.mapper.mapper.sql.level INHERIT
logger.org.objectweb.speedo.mapper.jorm-factory.level INHERIT
logger.org.objectweb.speedo.mapper.jorm-factory.class-properties.level INHERIT
logger.org.objectweb.speedo.mapper.pool.level INHERIT
logger.org.objectweb.speedo.mapper.storage-manager.level INHERIT
logger.org.objectweb.speedo.memory-instance-manager.level INHERIT
logger.org.objectweb.speedo.workingset-manager.level INHERIT
logger.org.objectweb.speedo.naming-manager-factory.level INHERIT
logger.org.objectweb.speedo.transaction.level INHERIT
logger.org.objectweb.speedo.tpm.level INHERIT
logger.org.objectweb.speedo.tpm.transactional-persistence-manager.level INHERIT
logger.org.objectweb.speedo.tpm.cache-manager.level INHERIT
logger.org.objectweb.speedo.tpm.cache-manager.bgcleaner.level INHERIT
logger.org.objectweb.speedo.tpm.concurrency-manager.level INHERIT
logger.org.objectweb.speedo.query-manager.level INHERIT
logger.org.objectweb.speedo.query-manager.compiled-query.level INHERIT
logger.org.objectweb.speedo.query-manager.compiled-query.allocator.level INHERIT
logger.org.objectweb.speedo.query-manager.compiled-query.parser.level INHERIT
logger.org.objectweb.speedo.query-manager.compiled-query.parser.variable.level
INHERIT
logger.org.objectweb.speedo.query-manager.compiled-query.parser.filter.level
INHERIT
logger.org.objectweb.speedo.compiled-query-cache.level INHERIT
logger.org.objectweb.speedo.jca.level INHERIT
logger.org.objectweb.speedo.txStatistic.level INHERIT
logger.org.objectweb.speedo.jmx.level INHERIT

# Struts
logger.org.apache.struts.util.level WARN

#------------------------------
# Tomcat 6 - Catalina logging
#------------------------------
logger.org.apache.catalina.core.ContainerBase.[jonas].level INFO
logger.org.apache.catalina.core.ContainerBase.[jonas].[localhost].level INFO
logger.org.apache.catalina.core.ContainerBase.[jonas].[localhost].[path].level
INFO
### example for jonasAdmin ###
logger.org.apache.catalina.core.ContainerBase.[jonas].[localhost].[jonasAdmin].level
INFO

#-----------------------------
# Jetty 6 (Avoid log of MBean registration (info level)
#-----------------------------
logger.org.mortbay.util.jmx.ModelMBeanImpl.level ERROR

#-----------------------------
# Apache CXF
#-----------------------------
logger.org.apache.cxf.level INHERIT
# Avoid a log diplaying erroneous informations (INFO level)
# TODO remove theses lines when a proper startup message policy will be decided
logger.org.apache.cxf.endpoint.ServerImpl.level ERROR

#-----------------------------
# Open Symphony Quartz
#-----------------------------
logger.org.quartz.level INHERIT
# Avoid logs of unwanted informations (INFO level)
# TODO remove theses lines when a proper startup message policy will be decided
logger.org.quartz.core.QuartzScheduler.level ERROR
logger.org.quartz.simpl.RAMJobStore.level ERROR
logger.org.quartz.impl.StdSchedulerFactory.level ERROR

# -----------------------------------------------------------------------
# MX4J - also need to set system proprty mx4j.log.priority to the
corresponding level
# (fatal, error, warn, info, debug, trace)
# -----------------------------------------------------------------------
logger.mx4j.level ERROR

#-----------------------------
# OSGi logging
#-----------------------------
logger.org.ow2.util.log.impl.osgi.level ERROR

#-----------------------------
# Deployment plan logging
#-----------------------------
logger.org.ow2.util.plan.deployer.impl.level ERROR

#---------
# File logger for JGroups
# JGroups
#---------
handler.all_jgroups.type File
handler.all_jgroups.output all_jgroups.log
handler.all_jgroups.pattern %d : %l : %h : %O{1}.%M : %m%n
logger.org.jgroups.level FATAL
logger.org.jgroups.handler.0 all_jgroups
logger.org.jgroups.additivity false

# -----------------------------------------------------------------------
# For Log file (tests)
# -----------------------------------------------------------------------
handler.logtest.type File
handler.logtest.output jonas_tests.log
handler.logtest.pattern %d : %l : %h : %O{1}.%M : %m%n
logger.org.ow2.jonas_tests.history.level INFO
logger.org.ow2.jonas_tests.history.handler.0 logtest
logger.org.ow2.jonas_tests.history.additivity false


#---
# Discovery Logger configuration
#uncomment these lines to configure a file logger for jonas discovery
#handler.jonas-discovery.type File
#handler.jonas-discovery.output jonas_discovery.log
#handler.jonas-discovery.pattern %d : %l : %h : %O{1}.%M : %m%n
# Don't forget to set logs level.
logger.org.ow2.jonas.discovery.level INFO
#logger.org.ow2.jonas.discovery.handler.0 jonas-discovery
#logger.org.ow2.jonas.discovery.additivity false

#---
#Granite Logger configuration
handler.granite-ds.type File
handler.granite-ds.output granite-ds.log
handler.granite-ds.pattern %d : %l : %h : %O{1}.%M : %m%n
# Don't forget to set logs level.
logger.org.granite.config.level INFO
logger.org.granite.config.handler.0 granite-ds
logger.org.granite.config.additivity false

#----------
# PrivateCompany
#----------

logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG



On 18 August 2011 15:57, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
logger.<name>.level <level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Guillaume Sauthier (OW2)
2011-08-18 15:13:15 UTC
Permalink
Please set back the monolog configuration to javaLog:
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory

Easybeans is printing its debug information on a logger backed by Java util
Log.

--G
Post by Stefaan Somers
No luck either.
# -----------------------------------------------------------------------
# This is a default configuration file for monolog.
#
# 2 handlers have been defined : tty (System.out) and logf (file)
#
# %h the thread name
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file.
# Each logger inherits from its parent for properties not defined.
# The root logger is "root". It must always be defined.
#
# ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
#
# -> More info on http://www.objectweb.org/monolog/doc.html
# -----------------------------------------------------------------------
# -----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
# -----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory
# log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
logger.<name>.level <level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Paul Adriaenssens
2011-08-18 15:45:42 UTC
Permalink
Thanks a lot Guillaume,

Stefaan, I changed that monolog configuration and now we see a lot of
Easybeans debug messages in our logfile. I will show you tomorrow ...

Best Regards,

Paul Adriaenssens
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by Java util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
#
# 2 handlers have been defined : tty (System.out) and logf (file)
#
# %h the thread name
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file.
# Each logger inherits from its parent for properties not defined.
# The root logger is "root". It must always be defined.
#
# ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
#
# -> More info on http://www.objectweb.org/monolog/doc.html
#
-----------------------------------------------------------------------
#
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory
# log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
logger.<name>.level <level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory
to
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
Post by Guillaume Sauthier (OW2)
Post by Stefaan Somers
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Stefaan Somers
2011-08-18 19:34:45 UTC
Permalink
I've succeeded to set the logging right now. What I can see in the
log-files are many of the following entries :
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:36,953 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:43,359 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:43,359 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:51,235 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:51,266 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:58,907 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:58,907 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:06,814 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
2011-08-19 00:31:06,814 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:15,111 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext


Any idea what is going wrong, or is this normal behaviour??

Already many thnks for your help.

Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by Java util
Log.
--G
Post by Stefaan Somers
No luck either.
# -----------------------------------------------------------------------
# This is a default configuration file for monolog.
#
# 2 handlers have been defined : tty (System.out) and logf (file)
#
# %h    the thread name
# %O{1} the Class name (basename only)
# %M    the method name
# %L    the line number
# %d    the date
# %l    the level
# %m    the message itself
# %n    a new line
#
# A list of predefined loggers is given at the end of the file.
# Each logger inherits from its parent for properties not defined.
# The root logger is "root". It must always be defined.
#
# ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
#
# -> More info on http://www.objectweb.org/monolog/doc.html
# -----------------------------------------------------------------------
# -----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
# -----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory
# log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
logger.<name>.level <level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Florent BENOIT
2011-08-19 07:06:21 UTC
Permalink
This is normal behaviour but you should see some "elapsed time" for
bytecode injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container

logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG



Regards,

Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:36,953 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:43,359 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:43,359 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:51,235 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:51,266 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:58,907 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:58,907 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:06,814 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
2011-08-19 00:31:06,814 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:15,111 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by Java util
Log.
--G
Post by Stefaan Somers
No luck either.
# -----------------------------------------------------------------------
# This is a default configuration file for monolog.
#
# 2 handlers have been defined : tty (System.out) and logf (file)
#
# %h the thread name
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file.
# Each logger inherits from its parent for properties not defined.
# The root logger is "root". It must always be defined.
#
# ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
#
# -> More info on http://www.objectweb.org/monolog/doc.html
# -----------------------------------------------------------------------
# -----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
# -----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory
# log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Stefaan Somers
2011-08-23 07:16:51 UTC
Permalink
Hi Florent,

many thanks for answering already. I've set the logging as asked, but
it doesn't give me much more information.
Is it normal that these entry-lines appear for every bean defined.
Is there any possibility to make that the bean is not
container-managed. If so what are the consequences??

Greetings
This is normal behaviour but you should see some "elapsed time" for bytecode
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:36,953 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:43,359 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:43,359 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:51,235 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:51,266 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:30:58,907 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
2011-08-19 00:30:58,907 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:06,814 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
2011-08-19 00:31:06,814 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:15,111 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by Java util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
#
# 2 handlers have been defined : tty (System.out) and logf (file)
#
# %h    the thread name
# %O{1} the Class name (basename only)
# %M    the method name
# %L    the line number
# %d    the date
# %l    the level
# %m    the message itself
# %n    a new line
#
# A list of predefined loggers is given at the end of the file.
# Each logger inherits from its parent for properties not defined.
# The root logger is "root". It must always be defined.
#
# ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
#
# ->  More info on http://www.objectweb.org/monolog/doc.html
#
-----------------------------------------------------------------------
#
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory
# log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Post by Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ?
So that we can see where time is consumed.
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the startup
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding factory to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Greetings,
Stefaan Somers
Paul Adriaenssens
2011-08-23 12:38:04 UTC
Permalink
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
'createSubcontext env' and the logging of the line with 'createSubcontext
comp'?

2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
....
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext
comp

Currently for one of our applications containing 290 generated SLSB's the
JOnAS startup takes about 1 hour!

You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on ftp://ftps.provant.be/jonas-start.log

Also this process seems to slow down, in the beginning it takes about 1,5
sec per SLSB, at the end about 8 sec.

Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an optimal
way ...

Or is it normal behaviour when a large number of SLSB's is used?

Kind Regards,

Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but it
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file) #
# Patterns for each handler may include these possible values : # %h
   the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M    the method name
# %L    the line number
# %d    the date
# %l    the level
# %m    the message itself
# %n    a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. #
The root logger is "root". It must always be defined.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# ->  More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Paul Adriaenssens
2011-08-23 12:44:12 UTC
Permalink
Here the correct URL to access the DEBUG level logfile:
ftp://applicaties:***@ftps.provant.be

Paul
Post by Paul Adriaenssens
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
'createSubcontext env' and the logging of the line with 'createSubcontext
comp'?
2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
....
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext
comp
Currently for one of our applications containing 290 generated SLSB's the
JOnAS startup takes about 1 hour!
You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on ftp://ftps.provant.be/jonas-start.log
Also this process seems to slow down, in the beginning it takes about 1,5
sec per SLSB, at the end about 8 sec.
Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an optimal
way ...
Or is it normal behaviour when a large number of SLSB's is used?
Kind Regards,
Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but it
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file) #
# Patterns for each handler may include these possible values : # %h
   the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M    the method name
# %L    the line number
# %d    the date
# %l    the level
# %m    the message itself
# %n    a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. #
The root logger is "root". It must always be defined.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# ->  More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Florent BENOIT
2011-08-23 13:13:03 UTC
Permalink
Hi,

Could you try to make a new run with :

1/ Launching JOnAS with the following system property :
-Deasybeans.useSimplePool=true

2/ Try with another persistence provider
JONAS_BASE/conf/jonas.properties (change from hibernate to eclipselink
for example)

Also, I'm interested in having the ear in order to reproduce your problem

Regards,

Florent
Paul
Post by Paul Adriaenssens
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
'createSubcontext env' and the logging of the line with 'createSubcontext
comp'?
2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
....
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext
comp
Currently for one of our applications containing 290 generated SLSB's the
JOnAS startup takes about 1 hour!
You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on ftp://ftps.provant.be/jonas-start.log
Also this process seems to slow down, in the beginning it takes about 1,5
sec per SLSB, at the end about 8 sec.
Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an optimal
way ...
Or is it normal behaviour when a large number of SLSB's is used?
Kind Regards,
Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but it
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file) #
# Patterns for each handler may include these possible values : # %h
the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. #
The root logger is "root". It must always be defined.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# -> More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Stefaan Somers
2011-08-24 08:01:33 UTC
Permalink
Hi Florent,

we tried both options but without any success :
1) no change
2) takes only 1 minute less (12 minutes -> 11 minutes)

Did you already had a chance to deploying the ear-file??

Greetings
   Hi,
-Deasybeans.useSimplePool=true
2/ Try with another persistence provider
JONAS_BASE/conf/jonas.properties (change from hibernate to eclipselink for
example)
Also, I'm interested in having the ear in order to reproduce your problem
Regards,
Florent
Paul
Post by Paul Adriaenssens
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
'createSubcontext env' and the logging of the line with 'createSubcontext
comp'?
2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
....
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext
comp
Currently for one of our applications containing 290 generated SLSB's the
JOnAS startup takes about 1 hour!
You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on
ftp://ftps.provant.be/jonas-start.log
Also this process seems to slow down, in the beginning it takes about 1,5
sec per SLSB, at the end about 8 sec.
Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an optimal
way ...
Or is it normal behaviour when a large number of SLSB's is used?
Kind Regards,
Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but it
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file) #
# Patterns for each handler may include these possible values : # %h
   the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M    the method name
# %L    the line number
# %d    the date
# %l    the level
# %m    the message itself
# %n    a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. #
The root logger is "root". It must always be defined.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# ->    More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Florent BENOIT
2011-08-24 12:09:11 UTC
Permalink
Hi,

I was able to deploy your EAR
You should comment the <statistics> component located in
JONAS_BASE/conf/easybeans-jonas.xml file

Regards,

Florent
Post by Stefaan Somers
Hi Florent,
1) no change
2) takes only 1 minute less (12 minutes -> 11 minutes)
Did you already had a chance to deploying the ear-file??
Greetings
Post by Florent BENOIT
Hi,
-Deasybeans.useSimplePool=true
2/ Try with another persistence provider
JONAS_BASE/conf/jonas.properties (change from hibernate to eclipselink for
example)
Also, I'm interested in having the ear in order to reproduce your problem
Regards,
Florent
Paul
Post by Paul Adriaenssens
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
'createSubcontext env' and the logging of the line with 'createSubcontext
comp'?
2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubcontext env
....
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext
comp
Currently for one of our applications containing 290 generated SLSB's the
JOnAS startup takes about 1 hour!
You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on
ftp://ftps.provant.be/jonas-start.log
Also this process seems to slow down, in the beginning it takes about 1,5
sec per SLSB, at the end about 8 sec.
Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an optimal
way ...
Or is it normal behaviour when a large number of SLSB's is used?
Kind Regards,
Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but it
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file) #
# Patterns for each handler may include these possible values : # %h
the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. #
The root logger is "root". It must always be defined.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# -> More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Stefaan Somers
2011-08-24 12:53:56 UTC
Permalink
Hi Florent,

we did the change (trum rufs.......) And yes indeed it performs a lot
faster now (still less than 5% of the time before). Many, many thanks

Now we still have the following questions :
1) isn't it better that by default this option is disabled for the
JONAS-server. Will avoid a lot of confusion for future users of the
Jonas-server
2) How did you see that this was causing the problem? Something in the
log-file???
3) now we have put this in comment, can this change something on the
behaviour of the application, or is it only used for administering
beans

Greetings
   Hi,
I was able to deploy your EAR
You should comment the <statistics> component located in
JONAS_BASE/conf/easybeans-jonas.xml file
Regards,
Florent
Post by Stefaan Somers
Hi Florent,
1) no change
2) takes only 1 minute less (12 minutes ->  11 minutes)
Did you already had a chance to deploying the ear-file??
Greetings
   Hi,
-Deasybeans.useSimplePool=true
2/ Try with another persistence provider
JONAS_BASE/conf/jonas.properties (change from hibernate to eclipselink for
example)
Also, I'm interested in having the ear in order to reproduce your problem
Regards,
Florent
Paul
Post by Paul Adriaenssens
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
'createSubcontext env' and the logging of the line with
'createSubcontext
comp'?
createSubcontext
env
....
createSubcontext
comp
Currently for one of our applications containing 290 generated SLSB's the
JOnAS startup takes about 1 hour!
You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on
ftp://ftps.provant.be/jonas-start.log
Also this process seems to slow down, in the beginning it takes about 1,5
sec per SLSB, at the end about 8 sec.
Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an optimal
way ...
Or is it normal behaviour when a large number of SLSB's is used?
Kind Regards,
Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but it
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file) #
# Patterns for each handler may include these possible values : # %h
   the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M    the method name
# %L    the line number
# %d    the date
# %l    the level
# %m    the message itself
# %n    a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. #
The root logger is "root". It must always be defined.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# ->      More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Florent BENOIT
2011-08-24 13:05:40 UTC
Permalink
Post by Stefaan Somers
Hi Florent,
we did the change (trum rufs.......) And yes indeed it performs a lot
faster now (still less than 5% of the time before). Many, many thanks
yes, the deployment is faster now.
Post by Stefaan Somers
1) isn't it better that by default this option is disabled for the
JONAS-server. Will avoid a lot of confusion for future users of the
Jonas-server
Maybe.
In fact I need to investigate because we don't have this issue with many
of EJB-JARs
Post by Stefaan Somers
2) How did you see that this was causing the problem? Something in the
log-file???
I perform some dump of the threads in order to see where we are
Post by Stefaan Somers
3) now we have put this in comment, can this change something on the
behaviour of the application, or is it only used for administering
beans
This is only used in order to collect statistics, this is not a core
component, so you won't see any change in your application

Regards,

Florent
Post by Stefaan Somers
Greetings
Post by Florent BENOIT
Hi,
I was able to deploy your EAR
You should comment the<statistics> component located in
JONAS_BASE/conf/easybeans-jonas.xml file
Regards,
Florent
Post by Stefaan Somers
Hi Florent,
1) no change
2) takes only 1 minute less (12 minutes -> 11 minutes)
Did you already had a chance to deploying the ear-file??
Greetings
Post by Florent BENOIT
Hi,
-Deasybeans.useSimplePool=true
2/ Try with another persistence provider
JONAS_BASE/conf/jonas.properties (change from hibernate to eclipselink for
example)
Also, I'm interested in having the ear in order to reproduce your problem
Regards,
Florent
Paul
Post by Paul Adriaenssens
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
'createSubcontext env' and the logging of the line with
'createSubcontext
comp'?
createSubcontext
env
....
createSubcontext
comp
Currently for one of our applications containing 290 generated SLSB's the
JOnAS startup takes about 1 hour!
You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on
ftp://ftps.provant.be/jonas-start.log
Also this process seems to slow down, in the beginning it takes about 1,5
sec per SLSB, at the end about 8 sec.
Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an optimal
way ...
Or is it normal behaviour when a large number of SLSB's is used?
Kind Regards,
Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but it
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean is
container managed so remove availability of java:comp/UserTransaction
object
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour??
Already many thnks for your help.
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file) #
# Patterns for each handler may include these possible values : # %h
the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. #
The root logger is "root". It must always be defined.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# -> More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Paul Adriaenssens
2011-08-23 14:35:20 UTC
Permalink
Ok Florent,

We're currently working on your 2 suggestions, thanks for that!

Also, we've put programmeringsToolDLOG.ear (ear of the large application)
on the same location as the previous logfile (from the small application),
together with some property files and the logfile jonas-progToolApp.log
containing the logs of the startup of the large application on a Debian
system ...

Best regards,

Paul
Post by Florent BENOIT
Hi,
-Deasybeans.useSimplePool=true
2/ Try with another persistence provider
JONAS_BASE/conf/jonas.properties (change from hibernate to eclipselink
for example)
Post by Florent BENOIT
Also, I'm interested in having the ear in order to reproduce your
problem
Post by Florent BENOIT
Regards,
Florent
Paul
Post by Paul Adriaenssens
Actually the question is if it's normal that it takes approximately 8
seconds for each SLSB between the logging of the line with
Post by Florent BENOIT
Post by Paul Adriaenssens
'createSubcontext env' and the logging of the line with
'createSubcontext
comp'?
createSubcontext
env
....
createSubcontext
comp
Currently for one of our applications containing 290 generated SLSB's
the
Post by Florent BENOIT
Post by Paul Adriaenssens
JOnAS startup takes about 1 hour!
You can find the full DEBUG level logfile of one of our generated
applications containing 83 SLSB's on
Post by Florent BENOIT
Post by Paul Adriaenssens
ftp://ftps.provant.be/jonas-start.log
Also this process seems to slow down, in the beginning it takes about
1,5
Post by Florent BENOIT
Post by Paul Adriaenssens
sec per SLSB, at the end about 8 sec.
Presumably we use somewhere a wrong configuration; or the source code
(Bean class, Data class, persistence.xml) is not generated in an
optimal
Post by Florent BENOIT
Post by Paul Adriaenssens
way ...
Or is it normal behaviour when a large number of SLSB's is used? Kind
Regards,
Post by Florent BENOIT
Post by Paul Adriaenssens
Paul
Post by Stefaan Somers
Hi Florent,
many thanks for answering already. I've set the logging as asked, but
it
Post by Florent BENOIT
Post by Paul Adriaenssens
doesn't give me much more information.
Post by Stefaan Somers
Is it normal that these entry-lines appear for every bean defined. Is
there any possibility to make that the bean is not
Post by Stefaan Somers
container-managed. If so what are the consequences??
Greetings
Post by Florent BENOIT
This is normal behaviour but you should see some "elapsed time" for
bytecode
Post by Stefaan Somers
Post by Florent BENOIT
injection, bytecode processing, etc.
Try to set debug to only org.ow2.easybeans.container.JContainer3 or
org.ow2.easybeans.container
Post by Stefaan Somers
Post by Florent BENOIT
logger.org.ow2.easybeans.container.JContainer3.level DEBUG
logger.org.ow2.easybeans.container.level DEBUG
Regards,
Florent
Post by Stefaan Somers
I've succeeded to set the logging right now. What I can see in the
2011-08-19 00:30:36,953 : JavaCompExtensionListener.handle : Bean
is
Post by Florent BENOIT
Post by Paul Adriaenssens
container managed so remove availability of java:comp/UserTransaction
object
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:36,953 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:36,953 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:43,359 : JavaCompExtensionListener.handle : Bean
is
Post by Florent BENOIT
Post by Paul Adriaenssens
container managed so remove availability of java:comp/UserTransaction
object
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:43,359 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:43,359 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:51,235 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,235 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:51,250 : JavaCompExtensionListener.handle : Bean
is
Post by Florent BENOIT
Post by Paul Adriaenssens
container managed so remove availability of java:comp/UserTransaction
object
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:51,250 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:51,250 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.lookup : lookup comp
2011-08-19 00:30:58,907 : JavaCompExtensionListener.handle : Bean
is
Post by Florent BENOIT
Post by Paul Adriaenssens
container managed so remove availability of java:comp/UserTransaction
object
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:30:58,907 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:30:58,907 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:06,814 : JavaCompExtensionListener.handle : Bean
is
Post by Florent BENOIT
Post by Paul Adriaenssens
container managed so remove availability of java:comp/UserTransaction
object
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:06,814 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:06,814 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:15,111 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,111 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:15,127 : JavaCompExtensionListener.handle : Bean
is
Post by Florent BENOIT
Post by Paul Adriaenssens
container managed so remove availability of java:comp/UserTransaction
object
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:15,127 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:15,127 : ContextImpl.bind : bind TimerService
createSubcontext
env
createSubcontext
comp
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind
UserTransaction
2011-08-19 00:31:23,096 : ContextImpl.rebind : rebind ORB
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,096 : ContextImpl.lookup : lookup comp
2011-08-19 00:31:23,096 : JavaCompExtensionListener.handle : Bean
is
Post by Florent BENOIT
Post by Paul Adriaenssens
container managed so remove availability of java:comp/UserTransaction
object
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
2011-08-19 00:31:23,112 : ContextImpl.unbind : unbind
UserTransaction
2011-08-19 00:31:23,112 : ContextImpl.bind : bind EJBContext
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Any idea what is going wrong, or is this normal behaviour?? Already
many thnks for your help.
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Greetings
On 18 August 2011 17:13, Guillaume Sauthier (OW2)
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
Easybeans is printing its debug information on a logger backed by
Java
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
util
Log.
--G
Post by Stefaan Somers
No luck either.
#
-----------------------------------------------------------------------
# This is a default configuration file for monolog.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# 2 handlers have been defined : tty (System.out) and logf (file)
#
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# Patterns for each handler may include these possible values : #
%h
Post by Florent BENOIT
Post by Paul Adriaenssens
the thread name
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
# %O{1} the Class name (basename only)
# %M the method name
# %L the line number
# %d the date
# %l the level
# %m the message itself
# %n a new line
#
# A list of predefined loggers is given at the end of the file. #
Each logger inherits from its parent for properties not defined. # The
root logger is "root". It must always be defined.
Post by Florent BENOIT
Post by Paul Adriaenssens
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# Each logger is associated with a level that can be one of : #
ERROR | WARN | INFO | DEBUG | FATAL | INHERIT
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
# -> More info on http://www.objectweb.org/monolog/doc.html #
-----------------------------------------------------------------------
Post by Florent BENOIT
Post by Paul Adriaenssens
#
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
-----------------------------------------------------------------------
# Define which wrapper to use (= javaLog)
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
#
-----------------------------------------------------------------------
# For Log4j you need to add log4j.jar
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
log.config.classname
org.objectweb.util.monolog.wrapper.log4j.MonologLoggerFactory #
log.config.classname
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
org.objectweb.util.monolog.wrapper.javaLog.LoggerFactory
#----------
# PrivateCompany
#----------
logger.net.democritus.level INFO
logger.com.privatecompany.level INFO
logger.net.palver.level INFO
logger.org.ow2.easybeans.level DEBUG
On 18 August 2011 15:57, Guillaume Sauthier (OW2)
logger.<name>.level<level>
you missed the .level
--G
Post by Stefaan Somers
Hi,
I included the following line in trace.properties, but I see no
logger.org.ow2.easybeans DEBUG
Greetings
On 18 August 2011 13:26, Guillaume Sauthier (OW2)
Maybe you can add traces for the org.ow2.easybeans logger ? So
that we can see where time is consumed.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
--G
Post by Stefaan Somers
Hi,
we have an application with many EJB's. Is it normal that the
startup
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
takes more than 10 minutes. Are there any steps I can do, to
troubleshoot this performance-problem.
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
18/08/11 13:02:26 (I) JCLLoggerAdapter.info : Not binding
factory
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
to
JNDI, no JNDI name configured
18/08/11 13:16:39 (I) JContainer3.start : Container
'D:\jonas-full-5.1.4\BASE\work\apps\jonas\pocAppEAR_2011.08.18-12.56.31.ear\pocAppEJB.jar'
[104 SLSB, 0 SFSB, 0 MDB] started in 891.270 ms
Post by Stefaan Somers
Post by Florent BENOIT
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Post by Stefaan Somers
Greetings,
Stefaan Somers
Loading...