persistence@glassfish.java.net

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

From: Mitesh Meswani <Mitesh.Meswani_at_Sun.COM>
Date: Thu, 12 Oct 2006 12:55:51 -0700

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