persistence@glassfish.java.net

Re: Code review for Easier configurable category-specific logging level

From: Wonseok Kim <guruwons_at_gmail.com>
Date: Tue, 3 Jul 2007 11:59:05 +0900

Hello Marina,
Comments in line...

On 7/3/07, Marina Vatkina <Marina.Vatkina_at_sun.com> wrote:
>
> Hi Wonseok,
>
> No, TLE code with java2db won't print SQL, but it should print some
> processing
> messages or not, depending on the settings. And global settings should not
> override the PU logging that's set only for a single category. Right?


Yes, I confirmed changing global logging level(with management console) does
not override category-specific logging level. This is also true for "
toplink.logging.level" property.

Oh, also I could see some category-specific(like connection category) logs
with java2db on at deployment time like below which does not appear with
java2db off.

[#|2007-07-03T11:49:
52.529+0900|CONFIG|sun-appserver9.1|oracle.toplink.essentials.session.file:/home/wons/works/toplink-essentials/publish/glassfish/domains/domain1/applications/j2ee-modules/JsfJpa.war/WEB-INF/classes/-jsf-jpa-war.connection|_ThreadID=33
;_ThreadName=Thread-76;|connecting(DatabaseLogin(
        platform=>JavaDBPlatform
        user name=> ""
        connector=>JNDIConnector datasource name=>null
))|#]

[#|2007-07-03T11:49:
52.529+0900|CONFIG|sun-appserver9.1|oracle.toplink.essentials.session.file:/home/wons/works/toplink-essentials/publish/glassfish/domains/domain1/applications/j2ee-modules/JsfJpa.war/WEB-INF/classes/-jsf-jpa-war.connection|_ThreadID=33;_ThreadName=Thread-76;|Connected:
jdbc:derby://localhost:1527/sun-appserv-samples;;create=true
        User: APP
        Database: Apache Derby Version: 10.2.1.6 - (452058)
        Driver: Apache Derby Network Client JDBC Driver Version: 10.2.2.1 -
(538595)|#]


What happens if 2 or more categories are chosen at different levels for the
> same PU?


With your question I also tested with several categories with different
logging levels like below.

    <properties>
      <property name="toplink.ddl-generation"
value="drop-and-create-tables"/>
      <property name="toplink.logging.level" value="WARNING"/>
      <property name="toplink.logging.level.sql" value="FINE"/>
      <property name="toplink.logging.level.connection" value="CONFIG"/>
      <property name="toplink.logging.level.properties" value="FINEST"/>
    </properties>

I also tried several times by changing above levels to check if
category-specific logs are logged or not. I could see each category logs are
printed correctly as expected - it was tedious to check every log messages
:)

thanks for your careful and precise advice~
Wonseok


thanks,
> -marina
>
> Wonseok Kim wrote:
> > Hi Marina,
> >
> > I tried to test your suggestions against GlassFish trunk.
> > I used two samples JsfJpa.war which has "toplink.logging.level.sql=FINE"
> > and JsfJpa2.war which has no logging setting.
> >
> > 1. JsfJpa.war - Correctly SQL category logs are logged and no other logs
> > below default INFO are not present.
> > 2. I changed the log level by management console to FINEST and confirmed
> > that all level logs appear. After that I changed the log level to INFO
> > and confirmed only SQL category FINE-level logs appears.
> > 4. I deployed two apps - JsfJpa.war and JsfJpa2.war. I confirmed only
> > the first app logs FINE-level SQL logs.
> >
> > For #3 Could you tell me what you expect in more detail? I tested all
> > apps with "toplink.ddl-generation=drop-and-create-tables " and deploy
> > --dropandcreatetables=true command. But I don't get what behavior could
> > be different with javadb on. Do you mean SQLs triggered by AS using jdbc
> > files generated by TopLink should appear also? I don't think that
> > toplink.logging.level.<category> should apply to AS SQL triggering code
> > which use different logger like "
> javax.enterprise.resource.jdo.codegen.ejb".
> >
> > You can check above logs in the attached server log.
> >
> > Thanks,
> > Wonseok
> >
> > On 6/29/07, *Marina Vatkina* <Marina.Vatkina_at_sun.com
> > <mailto:Marina.Vatkina_at_sun.com>> wrote:
> >
> > Hi Wonseok,
> >
> > The changes seem ok, with the following concerns:
> > 1. Please check that setting a category-specific logging level
> > doesn't override
> > the overall level.
> > 2. You should be able to go the the GF admin screen and change
> > persistence log
> > level there, then press "save" and the new global TLE log level
> > should apply
> > without overriding the category level (try switching between FINE
> > and INFO).
> > 3. Check if you get expected logging at deploy with java2db on.
> > 3. Please check that category-specific logging level applies only to
> > a single PU
> > (I used 2 small apps for that purpose).
> >
> > thanks,
> > -marina
> >
> > Wonseok Kim wrote:
> > > Hi Tom, Marina,
> > >
> > > I implemented category-specific logging level property described
> in
> > > issue 1338
> > > https://glassfish.dev.java.net/issues/show_bug.cgi?id=1338
> > > < https://glassfish.dev.java.net/issues/show_bug.cgi?id=1338>
> > >
> > > I introduced "toplink.logging.level.<category>" property in which
> > > <category> is the string defined in SessionLog like below.
> > >
> > > public static final String SQL = "sql";
> > > public static final String TRANSACTION = "transaction";
> > > public static final String EVENT = "event";
> > > public static final String CONNECTION = "connection";
> > > public static final String QUERY = "query";
> > > public static final String CACHE = "cache";
> > > public static final String PROPAGATION = "propagation";
> > > public static final String SEQUENCING = "sequencing";
> > > public static final String EJB = "ejb";
> > > public static final String DMS = "dms";
> > > public static final String EJB_OR_METADATA =
> "ejb_or_metadata";
> > > public static final String WEAVER = "weaver";
> > > public static final String PROPERTIES = "properties";
> > >
> > > If a user put a property like "toplink.logging.level.sql" with
> valid
> > > level value, this is set to SessionLog with setLevel(int level,
> > String
> > > category) method.
> > > Most expected usecase of this property is that users want to see
> only
> > > SQL logs without other verbose log. this is now possible with
> > > toplink.logging.level.sql=FINE
> > >
> > > I also added category-specific log level facility to
> > DefaultSessionLog
> > > class like JavaLog because DefaultSessionLog is the mostly used
> > one in
> > > Java SE environment.
> > >
> > > Please review this and let me know if I missed something.
> > > I confirmed that this new property works as expected both with
> > JavaLog
> > > and DefaultSessionLog.
> > >
> > > Thanks,
> > > Wonseok
> > >
> > >
> > >
> >
> ------------------------------------------------------------------------
> >
> > >
> > > Index:
> >
> entity-persistence/src/java/oracle/toplink/essentials/config/TopLinkProperties.java
> > >
> ===================================================================
> > > RCS file:
> >
> /cvs/glassfish/entity-persistence/src/java/oracle/toplink/essentials/config/TopLinkProperties.java,v
> >
> > > retrieving revision 1.7
> > > diff -c -w -r1.7 TopLinkProperties.java
> > > ***
> >
> entity-persistence/src/java/oracle/toplink/essentials/config/TopLinkProperties.java
> > 29 May 2007 14:57:43 -0000 1.7
> > > ---
> >
> entity-persistence/src/java/oracle/toplink/essentials/config/TopLinkProperties.java
> > 28 Jun 2007 16:56:45 -0000
> > > ***************
> > > *** 113,118 ****
> > > --- 113,125 ----
> > > // Valid values are names of levels defined in
> > java.util.logging.Level,
> > > // default value is java.util.logging.Level.CONFIG.getName
> ()
> > > public static final String LOGGING_LEVEL =
> > "toplink.logging.level";
> > > +
> > > + // Category-specific logging level prefix
> > > + // Property names formed out of this prefix by appending a
> > category name
> > > + // e.g.) toplink.logging.level.sql
> > > + // Valid categories are defined in SessionLog
> > > + public static final String CATEGORY_LOGGING_LEVEL_ = "
> > toplink.logging.level.";
> > > +
> > > // By default ("true") the date is always logged.
> > > // This can be turned off ("false").
> > > public static final String LOGGING_TIMESTAMP = "
> > toplink.logging.timestamp";
> > > Index:
> >
> entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/EntityManagerSetupImpl.java
> > >
> ===================================================================
> > > RCS file:
> >
> /cvs/glassfish/entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/EntityManagerSetupImpl.java,v
> > > retrieving revision 1.55
> > > diff -c -w -r1.55 EntityManagerSetupImpl.java
> > > ***
> >
> entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/EntityManagerSetupImpl.java
> > 30 May 2007 21:16:17 -0000 1.55
> > > ---
> >
> entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/EntityManagerSetupImpl.java
> > 28 Jun 2007 16:56:45 -0000
> > > ***************
> > > *** 998,1003 ****
> > > --- 998,1015 ----
> > > if(logLevelString != null) {
> > >
> > log.setLevel(AbstractSessionLog.translateStringToLoggingLevel
> (logLevelString));
> >
> > > }
> > > + // category-specific logging level
> > > + Map categoryLogLevelMap =
> > PropertiesHandler.getPrefixValuesLogDebug(
> TopLinkProperties.CATEGORY_LOGGING_LEVEL_,
> > m, session);
> > > + if(!categoryLogLevelMap.isEmpty()) {
> > > + Iterator it =
> > categoryLogLevelMap.entrySet().iterator();
> > > + while (it.hasNext()) {
> > > + Map.Entry entry = (Map.Entry)it.next();
> > > + String name = (String)entry.getKey();
> > > + String value = (String)entry.getValue();
> > > +
> > log.setLevel(AbstractSessionLog.translateStringToLoggingLevel
> (value),
> > name);
> > > + }
> > > + }
> > > +
> > > String tsString =
> > getConfigPropertyAsStringLogDebug(
> TopLinkProperties.LOGGING_TIMESTAMP,
> > m, session);
> > > if (tsString != null) {
> > > log.setShouldPrintDate(Boolean.parseBoolean
> > (tsString));
> > > Index:
> >
> entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/base/PropertiesHandler.java
> > >
> ===================================================================
> > > RCS file:
> >
> /cvs/glassfish/entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/base/PropertiesHandler.java,v
> >
> > > retrieving revision 1.8
> > > diff -c -w -r1.8 PropertiesHandler.java
> > > ***
> >
> entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/base/PropertiesHandler.java
> > 29 May 2007 14:57:44 -0000 1.8
> > > ---
> >
> entity-persistence/src/java/oracle/toplink/essentials/internal/ejb/cmp3/base/PropertiesHandler.java
> > 28 Jun 2007 16:56:46 -0000
> > > ***************
> > > *** 160,165 ****
> > > --- 160,166 ----
> > > static {
> > > addProp(new LoggerTypeProp());
> > > addProp(new LoggingLevelProp());
> > > + addProp(new CategoryLoggingLevelProp());
> > > addProp(new TargetDatabaseProp());
> > > addProp(new TargetServerProp());
> > > addProp(new CacheSizeProp());
> > > ***************
> > > *** 411,416 ****
> > > --- 412,435 ----
> > > }
> > > }
> > >
> > > + protected static class CategoryLoggingLevelProp extends
> Prop {
> > > + CategoryLoggingLevelProp() {
> > > + super(TopLinkProperties.CATEGORY_LOGGING_LEVEL_);
> > > + valueArray = new Object[] {
> > > + Level.OFF.getName(),
> > > + Level.SEVERE.getName(),
> > > + Level.OFF.getName(),
> > > + Level.WARNING.getName(),
> > > + Level.INFO.getName(),
> > > + Level.CONFIG.getName(),
> > > + Level.FINE.getName(),
> > > + Level.FINER.getName(),
> > > + Level.FINEST.getName(),
> > > + Level.ALL.getName()
> > > + };
> > > + }
> > > + }
> > > +
> > > protected static class TargetDatabaseProp extends Prop {
> > > TargetDatabaseProp() {
> > > super(TopLinkProperties.TARGET_DATABASE,
> > TargetDatabase.DEFAULT);
> > > Index:
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/AbstractSessionLog.java
> > >
> ===================================================================
> > > RCS file:
> >
> /cvs/glassfish/entity-persistence/src/java/oracle/toplink/essentials/logging/AbstractSessionLog.java,v
> > > retrieving revision 1.8
> > > diff -c -w -r1.8 AbstractSessionLog.java
> > > ***
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/AbstractSessionLog.java
> > 22 May 2007 23:54:44 -0000 1.8
> > > ---
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/AbstractSessionLog.java
> > 28 Jun 2007 16:56:46 -0000
> > > ***************
> > > *** 203,210 ****
> > > /**
> > > * PUBLIC:
> > > * <p>
> > > ! * Return the log level. Category is only needed in
> JavaLog
> > > ! * to extract name space for the Logger which the log level
> > belongs to.
> > > * </p><p>
> > > *
> > > * @return the log level
> > > --- 203,209 ----
> > > /**
> > > * PUBLIC:
> > > * <p>
> > > ! * Return the log level for the category name space.
> > > * </p><p>
> > > *
> > > * @return the log level
> > > ***************
> > > *** 232,239 ****
> > > /**
> > > * PUBLIC:
> > > * <p>
> > > ! * Set the log level. Category is only needed in JavaLog
> > > ! * to extract name space for the Logger which the log level
> > belongs to.
> > > * </p><p>
> > > *
> > > * @param level the new log level
> > > --- 231,237 ----
> > > /**
> > > * PUBLIC:
> > > * <p>
> > > ! * Set the log level for the category name space.
> > > * </p><p>
> > > *
> > > * @param level the new log level
> > > ***************
> > > *** 263,271 ****
> > > /**
> > > * PUBLIC:
> > > * <p>
> > > ! * Check if a message of the given level would actually be
> > logged. Category
> > > ! * is only needed in JavaLog to extract name space for the
> > Logger which the log
> > > ! * level belongs to. !isOff() is checked to screen out the
> > possibility when both
> > > * log level and log request level are set to OFF.
> > > * </p><p>
> > > *
> > > --- 261,268 ----
> > > /**
> > > * PUBLIC:
> > > * <p>
> > > ! * Check if a message of the given level would actually be
> > logged for the category name space.
> > > ! * !isOff() is checked to screen out the possibility when
> both
> > > * log level and log request level are set to OFF.
> > > * </p><p>
> > > *
> > > Index:
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/DefaultSessionLog.java
> > >
> ===================================================================
> > > RCS file:
> >
> /cvs/glassfish/entity-persistence/src/java/oracle/toplink/essentials/logging/DefaultSessionLog.java,v
> > > retrieving revision 1.5
> > > diff -c -w -r1.5 DefaultSessionLog.java
> > > ***
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/DefaultSessionLog.java 22
> > May 2007 23:54:44 -0000 1.5
> > > ---
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/DefaultSessionLog.java 28
> > Jun 2007 16:56:46 -0000
> > > ***************
> > > *** 37,42 ****
> > > --- 37,47 ----
> > > package oracle.toplink.essentials.logging;
> > >
> > > import java.io.*;
> > > + import java.util.HashMap;
> > > + import java.util.Map ;
> > > + import java.util.logging.Level;
> > > + import java.util.logging.Logger;
> > > +
> > > import oracle.toplink.essentials.exceptions.*;
> > > import oracle.toplink.essentials.internal.helper.*;
> > >
> > > ***************
> > > *** 66,77 ****
> > > --- 71,92 ----
> > > protected String fileName;
> > >
> > > /**
> > > + * Represents the Map that stores log levels per the name
> > space strings.
> > > + * The keys are category names. The values are log levels.
> > > + */
> > > + private Map<String, Integer> categoryLogLevelMap = new
> > HashMap();
> > > +
> > > + /**
> > > * PUBLIC:
> > > * Create a new default session log.
> > > */
> > > public DefaultSessionLog() {
> > > super();
> > > this.level = INFO;
> > > + for (int i = 0; i < loggerCategories.length ; i++) {
> > > + String loggerCategory = loggerCategories[i];
> > > + categoryLogLevelMap.put(loggerCategory, null);
> > > + }
> > > }
> > >
> > > /**
> > > ***************
> > > *** 90,95 ****
> > > --- 105,148 ----
> > > this.writer = writer;
> > > }
> > >
> > > +
> > > + @Override
> > > + public int getLevel(String category) {
> > > + if(category != null) {
> > > + Integer logLevel = categoryLogLevelMap.get
> (category);
> > > + // if category-specific log level is not set, use
> > parent level.
> > > + if(logLevel != null) {
> > > + return logLevel.intValue();
> > > + }
> > > + }
> > > + return level;
> > > + }
> > > +
> > > + @Override
> > > + public void setLevel(int level, String category) {
> > > + if(category == null) {
> > > + this.level = level;
> > > + } else if(categoryLogLevelMap.containsKey(category)) {
> > > + categoryLogLevelMap.put(category, level);
> > > + }
> > > + }
> > > +
> > > + /**
> > > + * PUBLIC:
> > > + * <p>
> > > + * Check if a message of the given level would actually be
> > logged by the logger
> > > + * with name space built from the given session and
> category.
> > > + * Return the shouldLog for the given category from
> > > + * </p><p>
> > > + * @return true if the given message level will be logged
> > > + * </p>
> > > + */
> > > + @Override
> > > + public boolean shouldLog(int level, String category) {
> > > + return (getLevel(category) <= level);
> > > + }
> > > +
> > > +
> > > /**
> > > * INTERNAL:
> > > * Log the entry.
> > > ***************
> > > *** 97,103 ****
> > > * This must be synchronized as it will be called by many
> > threads in three-tier.
> > > */
> > > public synchronized void log(SessionLogEntry entry) {
> > > ! if (!shouldLog(entry.getLevel())) {
> > > return;
> > > }
> > >
> > > --- 150,156 ----
> > > * This must be synchronized as it will be called by many
> > threads in three-tier.
> > > */
> > > public synchronized void log(SessionLogEntry entry) {
> > > ! if (!shouldLog(entry.getLevel(), entry.getNameSpace()))
> {
> > > return;
> > > }
> > >
> > > Index:
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/JavaLog.java
> > >
> ===================================================================
> > > RCS file:
> >
> /cvs/glassfish/entity-persistence/src/java/oracle/toplink/essentials/logging/JavaLog.java,v
> >
> > > retrieving revision 1.9
> > > diff -c -w -r1.9 JavaLog.java
> > > ***
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/JavaLog.java 22
> > May 2007 23:54:44 -0000 1.9
> > > ---
> >
> entity-persistence/src/java/oracle/toplink/essentials/logging/JavaLog.java 28
> > Jun 2007 16:56:46 -0000
> > > ***************
> > > *** 140,145 ****
> > > --- 140,147 ----
> > > */
> > > public void setLevel(final int level, String category) {
> > > final Logger logger = getLogger(category);
> > > + if(logger == null) return;
> > > +
> > > AccessController.doPrivileged(new PrivilegedAction() {
> > > public Object run() {
> > > logger.setLevel(getJavaLevel(level));
> >
> >
> >