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

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 'createSubconte=
xt
> comp'?
>
> 2011-08-19 00:31:15,127 : ContextImpl.createSubcontext : createSubconte=
xt
> env
> ....
> 2011-08-19 00:31:23,096 : ContextImpl.createSubcontext : createSubconte=
xt
> comp
>
> Currently for one of our applications containing 290 generated SLSB's t=
he
> 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 optima=
l
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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 UserTransactio=
n
> 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]> =A0wrote:
>>>>> 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
> =A0 =A0the thread name
>>>>>> # %O{1} the Class name (basename only)
>>>>>> # %M =A0 =A0the method name
>>>>>> # %L =A0 =A0the line number
>>>>>> # %d =A0 =A0the date
>>>>>> # %l =A0 =A0the level
>>>>>> # %m =A0 =A0the message itself
>>>>>> # %n =A0 =A0a 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
>>>>>> #
>>>>>> # -> =A0More info on http://www.objectweb.org/monolog/doc.html #
>>>>>> ------------------------------------------------------------------=
-----
> #
>>>>>> ------------------------------------------------------------------=
-----
> # Define which wrapper to use (=3D 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]> =A0wrote:
>>>>>>> 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]> =A0wrote:
>>>>>>>>> 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
>
>
>
>
>