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 15:13:51 -0700

Hi Tom,

About the name (your other email) - we can use something else other than
"default", or we can document that a session named "default" will have
the same log level as the default logger (whether explicitly specified
or not).

Here are my thoughts about the options:

Tom Ware wrote:
> I am still brainstorming for ideas. So far here's all I have come up with.
>
> 1. Do not change the namespace

We know it causes all types of problems if PU properties apply to the
AbstractSessionLog.

> 2. Add a property that allows the default TopLink logging level to be
> set. (toplink.logging.level.default or something like that).

Do you mean for the AbstractSessionLog to ignore the current
toplink.logging.level specified in a PU and use the default unless
explicitly specified by the toplink.logging.level.default?
Can be an option.

> 3. Document the new property as the only way to change the logging level
> for pre-session-creation configuration (i.e.the only way to change the
> logging level of the default logger on AbstractSessionLog). Also,
> document the fact that setting the value of this property in any
> persistence unit could affect other persistence units and will override
> any parent logging setting.

No, it shouldn't override the parent, i.e. toplink.logging.level.default
will not affect toplink.logging.level.<very-long-constructed-session-name>.
This was the reason to add its own name to the default logger.

> 4. Only use the existing property (toplink.logging.level) to set the
> level of the session's log.

This will require a redeploy to apply a change, and doesn't solve the
problem of having separate log levels for separate PUs.

>
> I haven't completely thought it out, but figured I pass on the idea to
> start the discussion.

yes, let's sort it out (and document the result).

thanks,
-marina
>
> -Tom
>
>
> Tom Ware wrote:
>
>> Hi Marina,
>>
>> Thanks for the lesson:)
>>
>> As far as changing the namespace for the default logger to
>> "oracle.toplink.essentials.default", I have a concern. Isn't this the
>> same namespace as a session called "default"? I believe this could
>> cause problems.
>>
>> I still need to do some thinking about the issue of how we deal with
>> the logging level of the default Logger. It seems to me to
>> potentially be an issue regardless of what we do about this bug. I'll
>> let you know what I come up with.
>>
>> I think Wonsoek has replied to your question about the default
>> logging levels. Please let me know if you have additional questions.
>>
>> -Tom
>>
>> 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.
>>>
>>> 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?
>>>
>>> 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.
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>
>>
>>
>>
>>