persistence@glassfish.java.net

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

From: Tom Ware <tom.ware_at_oracle.com>
Date: Fri, 13 Oct 2006 09:26:48 -0400

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.

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

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

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

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

-- 
Tom Ware
Principal Software Engineer
Oracle Canada Inc.
Direct: (613) 783-4598
Email: tom.ware_at_oracle.com