Re: Re: Re: Re: Re: Re: Re: Re: Re: Re: Re: Re: Re: Binding takes for ages on Jonas-server. No additional info to troubleshoot

     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

On 08/24/2011 10:01 AM, Stefaan Somers wrote:
> 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
>
> On 23 August 2011 15:13, Florent BENOIT<[email protected]>  wrote:
>>     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
>>
>>
>>
>> On 08/23/2011 02:44 PM, Paul Adriaenssens wrote:
>>> Here the correct URL to access the DEBUG level logfile:
>>> ftp://applicaties:[email protected]
>>>
>>> Paul
>>>
>>>> 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
>>>>
>>>>> 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
>>>>> On 19 August 2011 09:06, Florent BENOIT<[email protected]>    wrote:
>>>>>> 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
>>>>>> On 08/18/2011 09:34 PM, Stefaan Somers wrote:
>>>>>>> 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)
>>>>>>> <[email protected]>      wrote:
>>>>>>>> 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
>>>>>>>> 2011/8/18 Stefaan Somers<[email protected]>
>>>>>>>>> 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
>>>>>>>>> #----------
>>>>>>>>> # 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)
>>>>>>>>> <[email protected]>      wrote:
>>>>>>>>>> the format is:
>>>>>>>>>> logger.<name>.level<level>
>>>>>>>>>> you missed the .level
>>>>>>>>>> --G
>>>>>>>>>> 2011/8/18 Stefaan Somers<[email protected]>
>>>>>>>>>>> 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)
>>>>>>>>>>> <[email protected]>      wrote:
>>>>>>>>>>>> Maybe you can add traces for the org.ow2.easybeans logger ? So
>>>> that we can see where time is consumed.
>>>>>>>>>>>> --G
>>>>>>>>>>>> 2011/8/18 Stefaan Somers<[email protected]>
>>>>>>>>>>>>> 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
>>>>
>>>>
>>>>
>>