persistence@glassfish.java.net

Re: Code review for: [Issue 1107] Logger defined by a property doesn't work]

From: Marina Vatkina <Marina.Vatkina_at_Sun.COM>
Date: Thu, 12 Oct 2006 18:49:42 -0700

Hi Mitesh,

Yes, currently only the TopLink code specifies the logging category.
This category should correspond (in general) to a sublogger for the particular
namespace.
The concern that I have is how would a user specify a category to log messages,
so that other categories still use the default (or parent) level?

I don't think we currently support an option of choosing a category in the
persistence.xml. But what would happen if the category is chosen globally via
a GF logging property? Wouldn't it be "oracle.toplink.essentials.<category>"?
If yes, we need to change the logger namespace to have the category before
the session name.

BTW, looking more at JavaLog code, I'm pretty sure that it currently doesn't
support separate levels for separate categories for the default logger, which
might be ok or not, depending on the use cases for that logger.

thanks,
-marina

Mitesh Meswani wrote:
>
>
> Marina Vatkina wrote:
>
>> Hi Mitesh,
>>
>> Mitesh Meswani wrote:
>>
>>> Marina,
>>>
>>> Please see inline...
>>>
>>> Marina Vatkina wrote:
>>>
>>>> Tom, Wonseok,
>>>>
>>>> Yes, I should've extracted the relevant portion into
>>>> setServerSessionName
>>>> (don't know why I missed half of the code :( - sorry about that).
>>>>
>>>> Yes, it should be ".default".
>>>>
>>>> The categories are appended to each name space, and I'm not sure the
>>>> categories
>>>> are implemented correctly now in the JavaLog if they are expected to be
>>>> specified by the user. But let's discuss this further, and see where
>>>> is the
>>>> right solution.
>>>
>>>
>>> AFAIK, the catagory is specified by toplink logging code when it
>>> calls in to log a message.
>>
>>
>> I was more concerned about the option to specify a log level for a
>> specific
>> category. If it's not possible, the current code works. If a user can
>> choose
>> oracle.toplink.essentials.connection=FINEST while keeping everything else
>> at the default level, it should be the parent namespace for all session
>> loggers for this category. Right?
>
> With the current naming scheme, the loggers always have the session name
> prefixed before the category. That is like
> "oracle.toplink.essentials.<sessionname>.connection. I don't think we
> have any mechanism implemented to specify logging level per category in
> persistence.xml. But, it would be possible to do set level of any logger
> using domain.xml by adding a property corresponding to its name to
> log-service element
>
> Regards,
> Mitesh
>
>> thanks,
>> -marina
>>
>>>
>>>>
>>>> Here is the problem that I'm trying to solve.
>>>>
>>>> Java loggers use parent's level if it is not explicitly set, but use
>>>> its own
>>>> level otherwise. There is no way to unset a level, once it's set
>>>> explicitly.
>>>> The namespace is registered with the LogMgr in the VM, which means
>>>> that as long
>>>> as you use the same name, you are getting the same Java logger
>>>> instance.
>>>>
>>>> Now, if a log level is specified in a persistence.xml as a property,
>>>> we do set
>>>> it currently on the default logger by processing AbstractSessionLog in
>>>> initOrUpdateLogging (which without ".default" equals to the overall
>>>> TopLink namespace of "oracle.toplink.essentials") , i.e. any other
>>>> PU after that will
>>>> use that level (if it doesn't specify it explicitly), or will
>>>> override it again
>>>> with its own setting if it is different. Which means that 2 PUs
>>>> can't have 2
>>>> different logging levels.
>>>>
>>>> Adding ".default" will give AbstractSessionLog it's own sub-space.
>>>>
>>>> Setting the ServerSession name much earlier, gives each PU it's own
>>>> sub-space.
>>>>
>>>> Now the subcategories (I had never tested, how would it work in GF):
>>>> the
>>>> current code constructs the corresponding namespace as:
>>>>
>>>> sessionNameSpace = DEFAULT_TOPLINK_NAMESPACE + "." + sessionName;
>>>> String loggerNameSpace = sessionNameSpace + "." + loggerCategory;
>>>>
>>>> It might be better to have it as
>>>> DEFAULT_TOPLINK_NAMESPACE + "." + loggerCategory + sessionName;
>>>>
>>>> Right?
>>>
>>>
>>> Can you give some more details on what would be the benefit of
>>> changing logger name space as above?
>>>
>>> Thanks,
>>> Mitesh
>>>
>>>>
>>>> I need to think more about changing the session name - we can't
>>>> unregister
>>>> a logger from a LogMgr, so changing a name will mean creating new
>>>> loggers,
>>>> right?
>>>>
>>>> Tom, about the new useParentLevel() - will it be OFF or INFO by
>>>> default,
>>>> if you don't specify the level in SE? Can you check?
>>>>
>>>> thanks,
>>>> -marina
>>>>
>>>> Tom Ware wrote:
>>>>
>>>>> Marina and Wonsoek,
>>>>>
>>>>> - Can you explain a bit more why you need to append ".default" to
>>>>> the default log namespace. How will this work in conjuction with
>>>>> the logger categories? How exactly is the current namespace
>>>>> causing issues? Will users have to now specify ".default" on all
>>>>> their categories? (e.g. oracle.toplink.essentials.default.sql) To
>>>>> me, this seems a bit less intuitive than being able to set the
>>>>> logging levels without the "default".
>>>>> - BTW: Assuming we can sort out the "default", I think the
>>>>> namespace is currently missing a dot. It looks like it is
>>>>> oracle.toplink.essentialsdefault.
>>>>>
>>>>> Additional comments inline:
>>>>>
>>>>> Wonseok Kim wrote:
>>>>>
>>>>>> Hi Marina,
>>>>>> comments in line...
>>>>>>
>>>>>> On 10/12/06, *Marina Vatkina* <Marina.Vatkina_at_sun.com
>>>>>> <mailto:Marina.Vatkina_at_sun.com>> wrote:
>>>>>>
>>>>>> Tom, Wonseok,
>>>>>>
>>>>>> Please review the changes.
>>>>>>
>>>>>> Major points are described below in the IT note. Other diffs:
>>>>>>
>>>>>> a) renamed initServerSession() to setServerSessionName(), removed
>>>>>> from it the
>>>>>> call to assignCMP3Policy(), and changed the javadoc comments as
>>>>>> they didn't
>>>>>> reflect the actual things happening in the method anyway;
>>>>>>
>>>>>> b) changed to call assignCMP3Policy() directly in place of the
>>>>>> previous
>>>>>> initServerSession() call;
>>>>>>
>>>>>> c) moved the call to setServerSessionName() to the beginning of
>>>>>> predeploy (see
>>>>>> the reason #3 below).
>>>>>>
>>>>>> Tom, do you see any problem with registering the session by name
>>>>>> so early? I
>>>>>> couldn't find any code in the EntityManagerSetupImpl that would
>>>>>> suggest that
>>>>>> it can be.
>>>>>>
>>>>>>
>>>>>> 1. Original initServerSession() does another things. Those calls
>>>>>> session.getDescriptors() but this is filled in predeploy phase.
>>>>>> Therefore I think this should not be called before predeploy
>>>>>> finishes.
>>>>>> How about making a new method "initSessionName()" by extracting
>>>>>> only the following code?
>>>>>>
>>>>>> // use default session name if none is provided
>>>>>> String name =
>>>>>> EntityManagerFactoryProvider.getConfigPropertyAsString(TopLinkProperties.SESSION_NAME,
>>>>>> m);
>>>>>> if(name == null) {
>>>>>> if (persistenceUnitInfo.getPersistenceUnitRootUrl() !=
>>>>>> null){
>>>>>> name =
>>>>>> persistenceUnitInfo.getPersistenceUnitRootUrl().toString() + "-" +
>>>>>> persistenceUnitInfo.getPersistenceUnitName();
>>>>>> } else {
>>>>>> name = persistenceUnitInfo.getPersistenceUnitName();
>>>>>> }
>>>>>> session.setName(name);
>>>>>> // session.log(SessionLog.FINEST,
>>>>>> SessionLog.PROPERTIES, "property_value_default", new
>>>>>> Object[]{TopLinkProperties.SESSION_NAME , name});
>>>>>> addSessionToGlobalSessionManager();
>>>>>> }
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> I think Wonsoek's suggestion is a good one. Let's only move the
>>>>> session name initialization code, and not the other code. The
>>>>> initServerSession() method does more than initialize the name.
>>>>>
>>>>>>
>>>>>> 2. (To Tom) Is it safe to call addSessionToGlobalSessionManager()
>>>>>> in this early step (with uninitialized session)?
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> There is really one issue with this call we should resolve.
>>>>> Details in the next item.
>>>>>
>>>>>>
>>>>>> 3. What if SESSION_NAME is set by user explicitly? Now
>>>>>> user-specified name is set later by updateSessionName() which is
>>>>>> called from updateServerSession() in deploy phase. I think we need
>>>>>> to set this user-specified name in "initSessionName()" also. But
>>>>>> current code appears to allow changing session name in deploy().
>>>>>> Then should logger should change? I'm confused.
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> When we are integrated with the Server, I believe, predeploy and
>>>>> deploy will be called with the same properties and therefore, the
>>>>> call to updateSessionName() should result in the same name as the
>>>>> call to initSessionName().
>>>>>
>>>>> In SE, the predeploy occurs before the call to
>>>>> createEntityManagerFactory(name, properties) and the deploy occurs
>>>>> after. The properties specified in the argument to
>>>>> createEntityManagerFactory() that method need to be considered.
>>>>> That is why the call is made in deploy as well.
>>>>>
>>>>> As a result of this, there is an issue we have to resolve in SE if
>>>>> we are calling addSessionToGlobalSessionManager() before the deploy
>>>>> phase.
>>>>>
>>>>> - What happens if we initialize with a session name, and the call
>>>>> to createEntityManagerFactory() has a different name. In this
>>>>> case, we cannot simply change the session name because sessions are
>>>>> hashed in SessionManager based on their name, so changing the name
>>>>> of the session will result in lookup problems.
>>>>>
>>>>>>
>>>>>> 4. (To Tom) This is another concern but related to #3. What is the
>>>>>> behaviour of session name property? If I specify the same session
>>>>>> name of two applications or two persistence units, could I share
>>>>>> ServerSession? But it doesn't seem to do it, because in
>>>>>> EntityManagerSetupImpl.predeploy() session is always newly created
>>>>>> like below regardless of the session name.
>>>>>>
>>>>>> session = new ServerSession(...);
>>>>>>
>>>>>> If session name property has no effect in JPA, I think it should
>>>>>> be removed and then there will be no confusion in #3.
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> Session name is used to store the session we use on the
>>>>> SessionManager. We expect the session name to be unique. If it is
>>>>> not, an exception will be thrown when the session is added to the
>>>>> SessionManager. Take a look at the
>>>>> addSessionToGlobalSessionManager() method.
>>>>>
>>>>>
>>>>>>
>>>>>>
>>>>>> d) I added an api to the SessionLog to allow for #1 below.
>>>>>> Another
>>>>>> option would
>>>>>> be to check for the log level being OFF, but it's more time
>>>>>> consuming to go up
>>>>>> the logging chain every time.
>>>>>>
>>>>>>
>>>>>> Then in Java SE, the default level of JavaLogger becomes INFO
>>>>>> while CONFIG is a default for DefaultLogger. It appears to be
>>>>>> inconsistent for the default level. I don't know why the default
>>>>>> level has been CONFIG for TopLink logger, how about changing it to
>>>>>> INFO consistently. Then we don't need to set default level
>>>>>> explicitly and to introduce new method "userParentLevel()" to
>>>>>> SessionLog interface.
>>>>>>
>>>>>> protected void initOrUpdateLogging(boolean init, Map m,
>>>>>> SessionLog log) {
>>>>>> String logLevelString =
>>>>>> PropertiesHandler.getPropertyValueLogDebug
>>>>>> (TopLinkProperties.LOGGING_LEVEL, m, session);
>>>>>> // Don't need to set default level. It will follow the default
>>>>>> level policy of the logger. INFO for DefaultSessionLog. Parent
>>>>>> logger's level(INFO normally) for JavaLog.
>>>>>> /*
>>>>>> if(logLevelString == null && init) {
>>>>>> logLevelString =
>>>>>> PropertiesHandler.getDefaultPropertyValueLogDebug(TopLinkProperties.LOGGING_LEVEL,
>>>>>> session);
>>>>>> }
>>>>>> */
>>>>>> if (logLevelString != null) {
>>>>>>
>>>>>> log.setLevel(AbstractSessionLog.translateStringToLoggingLevel(logLevelString));
>>>>>>
>>>>>> }
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> I just talked to our product manager and we agree that changing the
>>>>> JPA default to be the same as the default logger. (INFO) Does that
>>>>> remove the need for the useParentLevel() method?
>>>>>
>>>>> If we make this change, I think we should change the logging in
>>>>> translateOldProperties and warnOldProperties to INFO.
>>>>>
>>>>> -Tom
>>>>>
>>>>>>
>>>>>> Regards
>>>>>> - Wonseok
>>>>>>
>>>>>> Let me know if you see any problems with the proposed changes. I
>>>>>> tested with
>>>>>> 2 PUs being deployed, one with the explicit log level, and
>>>>>> another
>>>>>> without it.
>>>>>> I also tested dynamic change of the log levels, and server
>>>>>> restart. All seem
>>>>>> to work correctly.
>>>>>>
>>>>>> thanks,
>>>>>> -marina
>>>>>>
>>>>>> -------- Original Message --------
>>>>>> Subject: [Issue 1107] Logger defined by a property doesn't work
>>>>>> Date: Thu, 12 Oct 2006 01:56:44 +0000
>>>>>> From: mvatkina_at_dev.java.net <mailto:mvatkina_at_dev.java.net>
>>>>>> To: mvatkina_at_dev.java.net <mailto:mvatkina_at_dev.java.net>
>>>>>>
>>>>>> https://glassfish.dev.java.net/issues/show_bug.cgi?id=1107
>>>>>>
>>>>>>
>>>>>>
>>>>>> User mvatkina changed the following:
>>>>>>
>>>>>> What |Old value |New value
>>>>>>
>>>>>> ================================================================================
>>>>>>
>>>>>> Status|NEW |STARTED
>>>>>>
>>>>>> --------------------------------------------------------------------------------
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> ------- Additional comments from mvatkina_at_dev.java.net
>>>>>> <mailto:mvatkina_at_dev.java.net> Thu Oct 12 01:56:44 +0000
>>>>>> 2006 -------
>>>>>> There are apparently several issues to address -
>>>>>> 1.Do not set log level explicitly if not specified in the
>>>>>> properties - use the
>>>>>> parent logger's level (set by the container) instead.
>>>>>> 2. The default logger namespace should be a child of TopLink
>>>>>> namespace, e.g.
>>>>>> "oracle.toplink.essentials.default", otherwise AbstractSessionLog
>>>>>> will set the
>>>>>> explicit level for all TopLink loggers (overriding the container
>>>>>> settings) in
>>>>>> the VM on the first PU with the specified log level.
>>>>>> 3. ServerSession name must be set prior to setting the logger for
>>>>>> that session,
>>>>>> otherwise the logger is registered as the default logger, and its
>>>>>> level will
>>>>>> apply to all PUs in this VM.
>>>>>>
>>>>>> A note: the problem that can't be solved so far is switching
>>>>>> between explicitly
>>>>>> specified log level for a PU and the defalt app server level for
>>>>>> this namespace.
>>>>>> As there is no way to unset log level after it's set, the only
>>>>>> work around will
>>>>>> be to change the property value or restart the server.
>>>>>>
>>>>>>
>>>>>>
>>>>>