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 14:55:15 -0700

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?

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.
>>>>
>>>>
>>>>
>>>