Re: Log4j 1.3 Woes (Partial Fix and Suggested Patch)

[Jess Holle <je...@ptc.com>]

Okay, first off, I must apologize for going off half-cocked and somewhat 
rudely after running into issues earlier this week.

Secondly, I must admit that I was way offbase on some of my analysis of 
the binary compatibility issue due to:

   1. Too much haste (making waste) in trying to get the problem addressed
   2. Too much reading of the 1.3 compatibility/conversion recipes and
      not enough reading of the code, etc.
          * The docs really led me to believe that Priority and Category
            were being removed.  Nothing could be further from the
            truth, of course, when one looks at the code and examines
            binary compatibility from various angles.

That said I found the cause of the main binary compatibility issue I was 
running into (after I had addressed all source-level compatibilities):

    In log4j 1.3, Priority extends Level
        *but *in 1.2, Level extends Priority.

This flip-flop of the inheritance hierarchy avoided removing any classes 
and made things look cleaner.  Unfortunately, it drives the class 
verifier /absolutely /nuts in some cases -- at least in Java 5 Update 5, 
which is my target JVM.

I am attaching a patch that I'd like to see incorporated in log4j 1.3.  
It fixes this issue while keeping the code pretty clean as I see it.  
Yes, the Level constants move back to the Priority class, but, no, 
they're no longer repeated in both Level and Priority -- they're just 
Level objects in the Priority class.  I also made Priority abstract and 
its constructor package-private to avoid anyone creating non-Level 
Priority instances.

This would seem to clear up the most common binary compatibility issues 
I could find: those involving Level/Priority and Logger/Category.  Most 
of those I raised previously were figments of my imagination due to 
reading too much into the 1.3 recipe, but this one is quite real.

This does not address the remaining source and binary compatibility 
issues between log4j 1.2 and 1.3 -- and I'd urge the log4j community to 
round off some of these rough edges as well.  That said, I did manage to 
produce one set of source code that compiles and works with both 
versions (and now compiles against one version and runs with the other) 
and I believe the other issues will effect far fewer log4j users than 
the one addressed here.

I would also like to strongly urge a clearer statement of what is and is 
not happening in the 1.3 recipes.  Staying away from Category and 
Priority is good advice, but a little more information as to the fact 
that they're not going away, that the inheritance hierarchy is not 
changing, etc, would be helpful.

Finally, I hope to get a chance to chase the lack of appender removal 
and log level change event firings and propose patches for these issues 
as well.

--
Jess Holle

Re: Log4j 1.3 Woes (Partial Fix and Suggested Patch)

[Jess Holle <je...@ptc.com>]

P.S.  I filed bug #37735 
<http://issues.apache.org/bugzilla/show_bug.cgi?id=37735> on this and 
attached the patch to it.

Jess Holle wrote:

> Okay, first off, I must apologize for going off half-cocked and 
> somewhat rudely after running into issues earlier this week.
>
> Secondly, I must admit that I was way offbase on some of my analysis 
> of the binary compatibility issue due to:
>
>    1. Too much haste (making waste) in trying to get the problem addressed
>    2. Too much reading of the 1.3 compatibility/conversion recipes and
>       not enough reading of the code, etc.
>           * The docs really led me to believe that Priority and
>             Category were being removed.  Nothing could be further
>             from the truth, of course, when one looks at the code and
>             examines binary compatibility from various angles.
>
> That said I found the cause of the main binary compatibility issue I 
> was running into (after I had addressed all source-level compatibilities):
>
>     In log4j 1.3, Priority extends Level
>         *but *in 1.2, Level extends Priority.
>
> This flip-flop of the inheritance hierarchy avoided removing any 
> classes and made things look cleaner.  Unfortunately, it drives the 
> class verifier /absolutely /nuts in some cases -- at least in Java 5 
> Update 5, which is my target JVM.
>
> I am attaching a patch that I'd like to see incorporated in log4j 
> 1.3.  It fixes this issue while keeping the code pretty clean as I see 
> it.  Yes, the Level constants move back to the Priority class, but, 
> no, they're no longer repeated in both Level and Priority -- they're 
> just Level objects in the Priority class.  I also made Priority 
> abstract and its constructor package-private to avoid anyone creating 
> non-Level Priority instances.
>
> This would seem to clear up the most common binary compatibility 
> issues I could find: those involving Level/Priority and 
> Logger/Category.  Most of those I raised previously were figments of 
> my imagination due to reading too much into the 1.3 recipe, but this 
> one is quite real.
>
> This does not address the remaining source and binary compatibility 
> issues between log4j 1.2 and 1.3 -- and I'd urge the log4j community 
> to round off some of these rough edges as well.  That said, I did 
> manage to produce one set of source code that compiles and works with 
> both versions (and now compiles against one version and runs with the 
> other) and I believe the other issues will effect far fewer log4j 
> users than the one addressed here.
>
> I would also like to strongly urge a clearer statement of what is and 
> is not happening in the 1.3 recipes.  Staying away from Category and 
> Priority is good advice, but a little more information as to the fact 
> that they're not going away, that the inheritance hierarchy is not 
> changing, etc, would be helpful.
>
> Finally, I hope to get a chance to chase the lack of appender removal 
> and log level change event firings and propose patches for these 
> issues as well.
>
> --
> Jess Holle
>
>------------------------------------------------------------------------
>
>Index: Level.java
>===================================================================
>--- Level.java	(revision 349818)
>+++ Level.java	(working copy)
>@@ -36,99 +36,9 @@
>    @author Ceki G&uuml;lc&uuml;
>    @author Yoav Shapira
>  */
>-public class Level implements Serializable {
>-  /**
>-   * OFF level integer value.
>-   */
>-  public static final int OFF_INT = Integer.MAX_VALUE;
>+public class Level extends Priority {
> 
>   /**
>-   * FATAL level integer value.
>-   */
>-  public static final int FATAL_INT = 50000;
>-
>-  /**
>-   * ERROR level integer value.
>-   */
>-  public static final int ERROR_INT = 40000;
>-
>-  /**
>-   * WARN level integer value.
>-   */
>-  public static final int WARN_INT = 30000;
>-
>-  /**
>-   * INFO level integer value.
>-   */
>-  public static final int INFO_INT = 20000;
>-
>-  /**
>-   * DEBUG level integer value.
>-   */
>-  public static final int DEBUG_INT = 10000;
>-
>-  /**
>-   * TRACE level integer value.
>-   * @since 1.2.12
>-   */
>-  public static final int TRACE_INT = 5000;
>-
>-  /**
>-   * ALL level integer value.
>-   */
>-  public static final int ALL_INT = Integer.MIN_VALUE;
>-
>-  /**
>-   * The <code>OFF</code> has the highest possible rank and is
>-   * intended to turn off logging.
>-   */
>-  public static final Level OFF = new Level(OFF_INT, "OFF", 0);
>-
>-  /**
>-   * The <code>FATAL</code> level designates very severe error
>-   * events that will presumably lead the application to abort.
>-   */
>-  public static final Level FATAL = new Level(FATAL_INT, "FATAL", 0);
>-
>-  /**
>-   * The <code>ERROR</code> level designates error events that
>-   * might still allow the application to continue running.
>-   */
>-  public static final Level ERROR = new Level(ERROR_INT, "ERROR", 3);
>-
>-  /**
>-   * The <code>WARN</code> level designates potentially harmful situations.
>-   */
>-  public static final Level WARN = new Level(WARN_INT, "WARN", 4);
>-
>-  /**
>-   * The <code>INFO</code> level designates informational messages
>-   * that highlight the progress of the application at coarse-grained
>-   * level.
>-   */
>-  public static final Level INFO = new Level(INFO_INT, "INFO", 6);
>-
>-  /**
>-   * The <code>DEBUG</code> Level designates fine-grained
>-   * informational events that are most useful to debug an
>-   * application.
>-   */
>-  public static final Level DEBUG = new Level(DEBUG_INT, "DEBUG", 7);
>-
>-  /**
>-   * The <code>TRACE</code> Level designates finer-grained
>-   * informational events than the <code>DEBUG</code level.
>-   * @since 1.2.12
>-   */
>-  public static final Level TRACE = new Level(TRACE_INT, "TRACE", 7);
>-
>-  /**
>-   * The <code>ALL</code> has the lowest possible rank and is intended to
>-   * turn on all logging.
>-   */
>-  public static final Level ALL = new Level(ALL_INT, "ALL", 7);
>-
>-  /**
>    * The integer value of this Level instance.
>    */
>   transient int level;
>Index: Priority.java
>===================================================================
>--- Priority.java	(revision 349818)
>+++ Priority.java	(working copy)
>@@ -18,7 +18,9 @@
> // Contributors:  Kitching Simon <Si...@orange.ch>
> package org.apache.log4j;
> 
>+import java.io.Serializable;
> 
>+
> /**
>  * <font color="#AA4444">Refrain from using this class directly, use the 
>  * {@link Level} class instead</font>. 
>@@ -26,77 +28,104 @@
>  * @author Ceki G&uuml;lc&uuml; 
>  * @deprecated 
>  */
>-public class Priority extends Level {
>+public abstract class Priority implements Serializable {
>   
>-  private Priority(int level, String levelStr, int syslogEquivalent) {
>-    super(level, levelStr, syslogEquivalent);
>-  }
>+  /**
>+   * OFF level integer value.
>+   */
>+  public static final int OFF_INT = Integer.MAX_VALUE;
> 
>-  
>   /**
>-     The <code>FATAL</code> level designates very severe error
>-     events that will presumably lead the application to abort.
>+   * FATAL level integer value.
>    */
>-  //public static final Priority FATAL = new Level(FATAL_INT, "FATAL", 0);
>+  public static final int FATAL_INT = 50000;
> 
>   /**
>-     The <code>ERROR</code> level designates error events that
>-     might still allow the application to continue running.  */
>- // public static final Priority ERROR = new Level(ERROR_INT, "ERROR", 3);
>+   * ERROR level integer value.
>+   */
>+  public static final int ERROR_INT = 40000;
> 
>   /**
>-     The <code>WARN</code> level designates potentially harmful situations.
>-  */
>- // public static final Priority WARN = new Level(WARN_INT, "WARN", 4);
>+   * WARN level integer value.
>+   */
>+  public static final int WARN_INT = 30000;
> 
>   /**
>-     The <code>INFO</code> level designates informational messages
>-     that highlight the progress of the application at coarse-grained
>-     level.  */
>- // public static final Priority INFO = new Level(INFO_INT, "INFO", 6);
>+   * INFO level integer value.
>+   */
>+  public static final int INFO_INT = 20000;
> 
>   /**
>-     The <code>DEBUG</code> priority designates fine-grained
>-     informational events that are most useful to debug an
>-     application.  */
>-  //public static final Priority DEBUG = new Level(DEBUG_INT, "DEBUG", 7);
>+   * DEBUG level integer value.
>+   */
>+  public static final int DEBUG_INT = 10000;
> 
>+  /**
>+   * TRACE level integer value.
>+   * @since 1.2.12
>+   */
>+  public static final int TRACE_INT = 5000;
> 
>   /**
>-     Convert the string passed as argument to a priority. If the
>-     conversion fails, then this method returns {@link #DEBUG}.
>+   * ALL level integer value.
>+   */
>+  public static final int ALL_INT = Integer.MIN_VALUE;
> 
>-     @deprecated Please use the {@link Level#toLevel(String)} method instead.}
>+  /**
>+   * The <code>OFF</code> has the highest possible rank and is
>+   * intended to turn off logging.
>+   */
>+  public static final Level OFF = new Level(OFF_INT, "OFF", 0);
> 
>+  /**
>+   * The <code>FATAL</code> level designates very severe error
>+   * events that will presumably lead the application to abort.
>+   */
>+  public static final Level FATAL = new Level(FATAL_INT, "FATAL", 0);
> 
>-  */
>-//  public static Level toPriority(String sArg) {
>-//    return Level.toLevel(sArg);
>-//  }
>+  /**
>+   * The <code>ERROR</code> level designates error events that
>+   * might still allow the application to continue running.
>+   */
>+  public static final Level ERROR = new Level(ERROR_INT, "ERROR", 3);
> 
>   /**
>-    Convert an integer passed as argument to a priority. If the
>-    conversion fails, then this method returns {@link #DEBUG}.
>+   * The <code>WARN</code> level designates potentially harmful situations.
>+   */
>+  public static final Level WARN = new Level(WARN_INT, "WARN", 4);
> 
>-  */
>-//  public static Priority toPriority(int val) {
>-//    return toPriority(val, Priority.DEBUG);
>-//  }
>+  /**
>+   * The <code>INFO</code> level designates informational messages
>+   * that highlight the progress of the application at coarse-grained
>+   * level.
>+   */
>+  public static final Level INFO = new Level(INFO_INT, "INFO", 6);
> 
>   /**
>-    Convert an integer passed as argument to a priority. If the
>-    conversion fails, then this method returns the specified default.
>-  */
>-//  public static Priority toPriority(int val, Priority defaultPriority) {
>-//    return Level.toLevel(val, (Level) defaultPriority);
>-//  }
>+   * The <code>DEBUG</code> Level designates fine-grained
>+   * informational events that are most useful to debug an
>+   * application.
>+   */
>+  public static final Level DEBUG = new Level(DEBUG_INT, "DEBUG", 7);
> 
>   /**
>-     Convert the string passed as argument to a priority. If the
>-     conversion fails, then this method returns the value of
>-     <code>defaultPriority</code>.
>-  */
>-//  public static Priority toPriority(String sArg, Priority defaultPriority) {
>-//    return Level.toLevel(sArg, (Level) defaultPriority);
>-//  }
>+   * The <code>TRACE</code> Level designates finer-grained
>+   * informational events than the <code>DEBUG</code level.
>+   * @since 1.2.12
>+   */
>+  public static final Level TRACE = new Level(TRACE_INT, "TRACE", 7);
>+
>+  /**
>+   * The <code>ALL</code> has the lowest possible rank and is intended to
>+   * turn on all logging.
>+   */
>+  public static final Level ALL = new Level(ALL_INT, "ALL", 7);
>+  
>+  
>+  /**
>+     Prevent construction except from this package (i.e. by Level).
>+   */
>+  Priority() {
>+    // nothing to do here
>+  }
> }
>
>  
>
>------------------------------------------------------------------------
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>For additional commands, e-mail: log4j-dev-help@logging.apache.org
>

Re: Log4j 1.3 Woes (Partial Fix and Suggested Patch)

[Jess Holle <je...@ptc.com>]

Jess Holle wrote:

> Finally, I hope to get a chance to chase the lack of appender removal 
> and log level change event firings and propose patches for these 
> issues as well.

Attached is a patch that adds event firing upon appender removal and log 
level change.

Please take this patch.  The only real alternative I see is to remove 
the appenderRemovedEvent() and levelChangedEvent() methods from 
LoggerEventListener as they currently advertise events that will never 
be fired which is very misleading.  I think it is much preferable to 
actually fire these events, however -- especially levelChangedEvent() as 
that would be quite useful in some cases.

I'll file a bug so this does not get lost in the shuffle as well.

One coment:

I note the new locking strategy in Category and this seems a lot better 
than that in 1.2.  It looks pretty close to Java 5's locks in many 
respects (though I note the lack of re-entrancy, which is understandable 
here).

That said, I also note many code sections like:

    lock.getWriteLock();
    
    if ((appender == null) || (aai == null)) {
      // Nothing to do
    } else {
      aai.removeAppender(appender);
    }
    lock.releaseWriteLock();


I would be quite concerned about the maintainability of this code as it 
stands:

   1. It is easy for someone to accidentally add a return (e.g. instead
      of the "Nothing to do" comment) between the lock and unlock.
   2. Some chunk of code might someday throw an exception between the
      lock and unlock.

The standard pattern with Java 5 locks is:

    lock.getWriteLock();
    try
    {
      if ((appender == null) || (aai == null)) {
        // Nothing to do
      } else {
        aai.removeAppender(appender);
      }
    }
    finally
    {
      lock.releaseWriteLock();
    }

which handles both of these problems.

--
Jess Holle