Kedar -
I agree that the shutdown during startup message is confusing. This is
a side effect of the way we currently handle XA recovery processing
during startup. We just integrated a fix in this area today, so you
should not see any more "shutting down ..." messages during startup.
Jerome -
As a general logging strategy, it seems to me like the JBI framework is
doing the right thing here. The framework is issuing an INFO level log
entry when it starts a component container. Won't v3 do the same when
it loads containers/modules on-demand in response to a deployment (e.g.
start the PHP container when a PHP app is deployed)?
regards,
keith
Jerome Dochez wrote:
> when embedded in GF, that's exactly what I am saying. now, we can
> tolerate one message of course, but i seem the see at least 4 in the log
> that started the thread. 4 messages for something that you said was
> normal operational behaviour seems too many.
>
>
> On Apr 24, 2007, at 3:35 PM, Mark S White wrote:
>
>> So you're saying that we shouldn't even log a message that says "JBI
>> framework started"?
>> We shouldn't be logging anything at all during normal execution?
>>
>> Jerome Dochez wrote:
>>> This is right, however a normal run of a particular technology should
>>> not produce any message. For instance, deployment has tendencies of
>>> being too verbose, same here, if this type of message relate to
>>> normal function of your runtime, just don't say it. INFO should be
>>> used for information that is not an error yet denotes something
>>> different in your runtime environment.
>>>
>>> As pointed below, JMS is notoriously abusing the INFO level, while it
>>> should really use FINE for this type of logs.
>>>
>>> Jerome
>>>
>>> On Apr 24, 2007, at 2:40 PM, Mark S White wrote:
>>>
>>>> I was under the impression that WARNING or SEVERE messages were used
>>>> to indicate
>>>> a problem, and the INFO messages were merely to show normal
>>>> operations. I was not
>>>> aware that an INFO message should be used to indicate that there is
>>>> a problem.
>>>>
>>>> kedar wrote:
>>>>> Let me retry.
>>>>>
>>>>> It is bad to have too many generic messages in the server log at
>>>>> default log level.
>>>>> But it is usually at the developer's discretion to log a message at
>>>>> a level. Several
>>>>> messages are generic, in that they don't necessarily raise
>>>>> user/administrator's eye brows.
>>>>>
>>>>> This particular message that came during startup certainly catches
>>>>> an eye. You have
>>>>> to make an extra effort to convey the users that it is normal. If
>>>>> we have too many
>>>>> such messages that turn out to be "normal" because of release
>>>>> notes, documentation
>>>>> or pure experience, it just means that we are not logging things
>>>>> right.
>>>>>
>>>>> Again, this is not nit picking. A shutdown-like message during
>>>>> startup *actually*
>>>>> made me think whether all was well and prompted me to write this
>>>>> message.
>>>>>
>>>>>
>>>>> Mark S White wrote:
>>>>>> 2. The code that starts/stops components is unaware of whether it
>>>>>> is being called during
>>>>>> startup of the server. I'm not sure it's worth someone spending a
>>>>>> lot of time changing a
>>>>>> good bit of code to eliminate 2-3 messages at startup.
>>>>>>
>>>>>> kedar wrote:
>>>>>>> 1- We should fix it with other components (In fact, I am fixing one
>>>>>>> such useless message myself). There is no pointing out a single
>>>>>>> component. I agree, the llllllllong JMSRA message is just
>>>>>>> annoying.
>>>>>>>
>>>>>>> 2- I am not convinced that *at the startup of the server* users need
>>>>>>> to see that binding components are stopped and are restarted.
>>>>>>> It is
>>>>>>> OK to say that they are "started".
>>>>>>>
>>>>>>>
>>>>>>> Mark S White wrote:
>>>>>>>> The frequency of starting/stopping a component is going to be
>>>>>>>> quite low. We do believe this
>>>>>>>> message warrants being logged at the INFO level. If we don't log
>>>>>>>> these messages, then it would
>>>>>>>> be very difficult to troubleshoot a problem related to component
>>>>>>>> states, because we wouldn't
>>>>>>>> have any indication in the log about when a component was
>>>>>>>> started/stopped.
>>>>>>>>
>>>>>>>> Remember a component is effectively a container. Not logging
>>>>>>>> anything when a component is
>>>>>>>> stopped or started would be analogous to not logging anything
>>>>>>>> when a web container or EJB
>>>>>>>> container is stopped or started.
>>>>>>>>
>>>>>>>> I see a lot more clutter in server.log at the INFO level from
>>>>>>>> other areas, such as this:
>>>>>>>>
>>>>>>>> [#|2007-04-24T11:22:03.484-0700|INFO|sun-appserver9.1|javax.resourceadapter.mqjmsra.lifecycle|_ThreadID=10;_ThreadName=main;|MQJMSRA_EB1101:
>>>>>>>> run:EMBEDDED broker started with code =0|#]
>>>>>>>>
>>>>>>>> [#|2007-04-24T11:22:03.640-0700|INFO|sun-appserver9.1|javax.resourceadapter.mqjmsra.lifecycle|_ThreadID=10;_ThreadName=main;|MQJMSRA_RA1101:
>>>>>>>> SJSMQ JMS ResourceAdaapter configuration=
>>>>>>>> raUID =null
>>>>>>>> brokerType =EMBEDDED
>>>>>>>> brokerInstanceName =imqbroker
>>>>>>>> brokerBindAddress =null
>>>>>>>> brokerPort =9099
>>>>>>>> brokerHomeDir
>>>>>>>> =C:/d/open2/open-esb/install/as8\imq\bin\..
>>>>>>>> brokerVarDir
>>>>>>>> =C:/d/open2/open-esb/install/as8/domains/domain1\imq
>>>>>>>> brokerJavaDir =c:/Java/jdk1.5.0_09
>>>>>>>> brokerArgs =null
>>>>>>>> brokerStartTimeout =60000
>>>>>>>> adminUsername =admin
>>>>>>>> adminPassFile =C:\d\tmp\asmq7703.tmp
>>>>>>>> useJNDIRmiServiceURL =true
>>>>>>>> rmiRegistryPort =8886
>>>>>>>> startRmiRegistry =false
>>>>>>>> useSSLJMXConnector =true
>>>>>>>> brokerEnableHA =false
>>>>>>>> clusterId =null
>>>>>>>> brokerId =null
>>>>>>>> jmxServiceURL =null
>>>>>>>> dbType =null
>>>>>>>> dbProps ={}
>>>>>>>> dsProps ={}
>>>>>>>> ConnectionURL =
>>>>>>>> UserName =guest
>>>>>>>> ReconnectEnabled =true
>>>>>>>> ReconnectInterval =5000
>>>>>>>> ReconnectAttempts =3
>>>>>>>> AddressListBehavior =RANDOM
>>>>>>>> AddressListIterations =3
>>>>>>>> InAppClientContainer =false
>>>>>>>> InClusteredContainer =false
>>>>>>>> GroupName =null
>>>>>>>> |#]
>>>>>>>>
>>>>>>>> [#|2007-04-24T11:22:03.640-0700|INFO|sun-appserver9.1|javax.resourceadapter.mqjmsra.lifecycle|_ThreadID=10;_ThreadName=main;|MQJMSRA_RA1101:
>>>>>>>> start:SJSMQ JMSRA Connection Factory
>>>>>>>> Config={imqOverrideJMSPriority=false, imqConsumerFlowLimit=1000,
>>>>>>>> imqOverrideJMSExpiration=false, imqAddressListIterations=3,
>>>>>>>> imqLoadMaxToServerSession=true, imqConnectionType=TCP,
>>>>>>>> imqPingInterval=30, imqSetJMSXUserID=false,
>>>>>>>> imqConfiguredClientID=,
>>>>>>>> imqSSLProviderClassname=com.sun.net.ssl.internal.ssl.Provider,
>>>>>>>> imqJMSDeliveryMode=PERSISTENT, imqConnectionFlowLimit=1000,
>>>>>>>> imqConnectionURL=http://localhost/imq/tunnel,
>>>>>>>> imqBrokerServiceName=, imqJMSPriority=4,
>>>>>>>> imqBrokerHostName=localhost, imqJMSExpiration=0,
>>>>>>>> imqAckOnProduce=, imqEnableSharedClientID=false,
>>>>>>>> imqAckTimeout=0, imqAckOnAcknowledge=,
>>>>>>>> imqConsumerFlowThreshold=50, imqDefaultPassword=guest,
>>>>>>>> imqQueueBrowserMaxMessagesPerRetrieve=1000,
>>>>>>>> imqDefaultUsername=guest, imqReconnectEnabled=false,
>>>>>>>> imqConnectionFlowCount=100, imqAddressListBehavior=PRIORITY,
>>>>>>>> imqReconnectAttempts=3, imqSetJMSXAppID=false,
>>>>>>>> imqConnectionHandler=com.sun.messaging.jmq.jmsclient.protocol.tcp.TCPStreamHandler,
>>>>>>>> imqSetJMSXRcvTimestamp=false, imqBrokerServicePort=0,
>>>>>>>> imqDisableSetClientID=false, imqSetJMSXConsumerTXID=false,
>>>>>>>> imqOverrideJMSDeliveryMode=false, imqBrokerHostPort=7676,
>>>>>>>> imqQueueBrowserRetrieveTimeout=60000,
>>>>>>>> imqSetJMSXProducerTXID=false, imqSSLIsHostTrusted=false,
>>>>>>>> imqConnectionFlowLimitEnabled=false, imqReconnectInterval=5000,
>>>>>>>> imqAddressList=localhost:9099,
>>>>>>>> imqOverrideJMSHeadersToTemporaryDestinations=false}|#]
>>>>>>>>
>>>>>>>> [#|2007-04-24T11:22:03.640-0700|INFO|sun-appserver9.1|javax.resourceadapter.mqjmsra.lifecycle|_ThreadID=10;_ThreadName=main;|MQJMSRA_RA1101:
>>>>>>>> SJSMQ JMSRA Started|#]
>>>>>>>>
>>>>>>>> kedar wrote:
>>>>>>>>> Thank you, Mark.
>>>>>>>>>
>>>>>>>>> Is it required that the user sees that the binding components
>>>>>>>>> are being restarted? Is this log record required to be at the
>>>>>>>>> default ("INFO") log level?
>>>>>>>>>
>>>>>>>>> Kedar
>>>>>>>>>
>>>>>>>>> Mark S White wrote:
>>>>>>>>>> JBI is not stopping and starting up. What you are seeing is
>>>>>>>>>> that once a deployment has been
>>>>>>>>>> made to a component (such as the Java EE engine or the HTTP
>>>>>>>>>> binding), whenever the
>>>>>>>>>> system restarts, the component must be initialized in order to
>>>>>>>>>> inform it of the existing deployments.
>>>>>>>>>> This is required by the JSR208 specification, as components
>>>>>>>>>> are not required to persist any
>>>>>>>>>> deployment information. In the case you are seeing, the
>>>>>>>>>> components had a desired state of
>>>>>>>>>> shutdown, so after the initialization was done, JBI has shut
>>>>>>>>>> down the components to return
>>>>>>>>>> them to their desired states. JBI itself did not stop, it only
>>>>>>>>>> started. The component shutdowns
>>>>>>>>>> were part of the startup processing.
>>>>>>>>>>
>>>>>>>>>> kedar wrote:
>>>>>>>>>>> More often than not, upon server startup, I see messages like:
>>>>>>>>>>>
>>>>>>>>>>> [#|2007-04-24T11:08:11.503-0700|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|Application
>>>>>>>>>>> server startup complete.|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2007-04-24T11:21:38.233-0700|INFO|sun-appserver9.1|com.sun.jbi.framework|_ThreadID=17;_ThreadName=sun-javaee-engine;|JBIFW1166:
>>>>>>>>>>> Engine sun-javaee-engine has been shut down.|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2007-04-24T11:21:38.236-0700|INFO|sun-appserver9.1|sun-http-binding.com.sun.jbi.httpsoapbc.HttpSoapBindingLifeCycle|_ThreadID=18;_ThreadName=sun-http-binding;|HTTP
>>>>>>>>>>> SOAP binding shutdown completed.|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2007-04-24T11:21:38.236-0700|INFO|sun-appserver9.1|com.sun.jbi.framework|_ThreadID=18;_ThreadName=sun-http-binding;|JBIFW1166:
>>>>>>>>>>> Binding sun-http-binding has been shut down.|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2007-04-24T11:21:38.238-0700|INFO|sun-appserver9.1|com.sun.jbi.framework|_ThreadID=16;_ThreadName=httpSSLWorkerThread-4848-0;|JBIFW0012:
>>>>>>>>>>> JBI framework startup complete.|#]
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> Why is JBI stopping and then starting up?
>>>>>>>>>>>
>>>>>>>>>>> Thanks,
>>>>>>>>>>> Kedar
>>>>>>>>>>>
>>>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>>>
>>>>>>>>>>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>>>>>>>>>>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>
>>>>>>>>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>>>>>>>>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>> ---------------------------------------------------------------------
>>>>>>>
>>>>>>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>>>>>>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>>>>>>
>>>>>>
>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>>>>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>>>>
>>>>
>>>> --Open ESB Community (http://open-esb.org)
>>>> Check out my blog (http://blogs.sun.com/mwhite)
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>>>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>>
>>
>> --Open ESB Community (http://open-esb.org)
>> Check out my blog (http://blogs.sun.com/mwhite)
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
>> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe_at_glassfish.dev.java.net
> For additional commands, e-mail: dev-help_at_glassfish.dev.java.net
>
--
Sun's Open ESB Community (http://open-esb.org)