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: Fri, 13 Oct 2006 11:06:18 -0700

Hi Tom,

Tom Ware wrote:
> Hi Marina,
>
> Comments inline.
>
> Marina Vatkina wrote:
>
>> 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).
>>
>>
> I have a strong preference towards a solution that does not not make any
> potential session names into "reserved words" and will required some
> convincing that a solution that makes any session name into a "reserved
> word" is the only reasonable way forward.

No problem. Worth discussing ;)

>
>> 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.
>>
>>
> That's why I am trying to figure out an alternate way of dealing with
> the default logger stored on 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.
>>
>>
> Your interpretation of my suggestion is correct. I am open to other
> suggestions as well.
>
>>
>>
>>> 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.
>>
>>
> First, in case my phrasing was not clear, by "override the parent" I
> simply mean using that property to specify the logging level for
> "oracle.toplink.essentials" - not changing the logging level on the
> parent logger.

"oracle.toplink.essentials" is the parent logger for all other loggers.
The goal is to never set the level on that particular logger from any
of the PU properties.

>
> Assuming my initial phrasing was adequately understood, I am not sure I
> understand what you are saying here. If someone specifies
> toplink.logging.level.default, they are explicitly setting a logging
> level. Why shouldn't that set the level for
> "oracle.toplink.essentials"?

Setting the level for "oracle.toplink.essentials" explicitly breaks GF
integration, as it will not be possible to reset it to defaults dynamically:
the default value is not set on "oracle.toplink.essentials" - it's a property
that is not present for the defaults, but by Java logging defaults, i.e.
"" logger in our case.


  The one strange thing this setting does is
> it potentially has side effects for the next user of the default log.
> This setting is one that is likely to be only used while debugging (and
> infrequently, even then) due to the fact that there are very few
> messages at a more granular level that INFO(the default) that are
> written to the default logger. As a result, I am willing to live with
> that side effect as long as we adequately document it.
>
> What if we change the setting to toplink.logging.level.config or
> toplink.logging.level.default-logger, and ensure it does not have any
> effect on the session loggers.

Yes, we can have toplink.logging.level.default-logger mapped to the
"oracle.toplink.essentials.default-logger" namespace, which will not affect
any session loggers, but will use the same global defaults if not set explicitly.

>
>>
>>
>>> 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.
>>
>>
> What conditions cause us to need a redeploy for a change?

If a user once specified a toplink.logging.level in the persistence.xml,
they can't just remove that property to get the defaults. They need to
redeploy either way if they change persistence.xml, but they'll need to
either reset it to INFO, or restart the server after the redeploy to get
the defaults.

>
> If toplink.logging.level sets only the level of the sessions log. (i.e.
> for session "session1", only the logger in namespace
> "oracle.toplink.essentials.session1" is affected), doesn't this solve
> the problem of having separate log levels for separate PUs? Please
> forgive me if I am being missing something obvious.

Yes. It does. I think we now go in circles around the following proposal:

1. Existing toplink.logging.level property to affect only session loggers.
2. Introduce toplink.logging.level.default-logger property that will affect
AbstractSessionLog only and will be global for all PUs in this VM.

As we didn't discuss the categories behavior so far,
3. It's not possible to choose for a user a separate log level for separate
category.

Do you agree?

thanks,
-marina

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