Fwd: Small patch to display nested exceptions

[Ceki Gülcü <ce...@qos.ch>]

Here is a patch I received from Costin Manolache of
Tomcat fame. It is included both as an attachment and also listed below:

Index: WriterAppender.java
===================================================================
RCS file: 
/home/cvspublic/jakarta-log4j/src/java/org/apache/log4j/WriterAppender.java,v
retrieving revision 1.23
diff -u -r1.23 WriterAppender.java
--- WriterAppender.java 7 May 2002 23:24:51 -0000       1.23
+++ WriterAppender.java 1 Aug 2002 23:35:31 -0000
@@ -8,11 +8,15 @@
  package org.apache.log4j;

  import java.io.IOException;
+import java.io.PrintWriter;
  import java.io.Writer;
  import java.io.OutputStream;
  import java.io.OutputStreamWriter;

+import java.lang.reflect.*;
+
  import org.apache.log4j.spi.ErrorHandler;
+import org.apache.log4j.spi.ThrowableInformation;
  import org.apache.log4j.spi.LoggingEvent;
  import org.apache.log4j.helpers.QuietWriter;
  import org.apache.log4j.helpers.LogLog;
@@ -297,20 +301,67 @@
      this.qw.write(this.layout.format(event));

      if(layout.ignoresThrowable()) {
-      String[] s = event.getThrowableStrRep();
-      if (s != null) {
-       int len = s.length;
-       for(int i = 0; i < len; i++) {
-         this.qw.write(s[i]);
-         this.qw.write(Layout.LINE_SEP);
-       }
-      }
+        ThrowableInformation ti=event.getThrowableInformation();
+        if( ti!=null ) {
+          Throwable t=ti.getThrowable();
+          PrintWriter pw=new PrintWriter(qw);
+          printThrowable( pw , t, "Root cause", 10 );
+          pw.flush();
+        }
      }

      if(this.immediateFlush) {
        this.qw.flush();
      }
    }
+
+  private static Object[] emptyObjectArray=new Object[0];
+
+  // From tomcat3.3
+  private static void printThrowable(PrintWriter w, Throwable t,
+                                     String rootcause, int depth )
+  {
+
+    if (t != null) {
+      // XXX XXX XXX Something seems wrong - DOS, permissions. Need to
+      // check.
+      t.printStackTrace(w);
+
+      // Find chained exception using few general patterns
+
+      Class tC=t.getClass();
+      Method mA[]= tC.getMethods();
+      Method nextThrowableMethod=null;
+      for( int i=0; i< mA.length ; i++  ) {
+        if( "getRootCause".equals( mA[i].getName() )
+            || "getNextException".equals( mA[i].getName() )
+            || "getException".equals( mA[i].getName() )) {
+                   // check param types
+          Class params[]=mA[i].getParameterTypes();
+          if( params==null || params.length==0 ) {
+            nextThrowableMethod=mA[i];
+            break;
+          }
+        }
+      }
+
+      if( nextThrowableMethod != null ) {
+        try {
+          Throwable nextT=(Throwable)nextThrowableMethod.
+            invoke( t , emptyObjectArray );
+          if( nextT != null ) {
+            w.println(rootcause);
+            if( depth > 0 ) {
+              printThrowable(w, nextT, rootcause, depth-1);
+            }
+          }
+        } catch( Exception ex ) {
+          // ignore
+        }
+      }
+    }
+  }
+


What this patch does is to enhance exception printing by recursively
printing any embedded exceptions. The patch will work if logging is
performed on the same JVM where the exception was created. However, it
will *not* work after logging event serialization because the
throwable field in ThrowableInformation is transient:

package org.apache.log4j.spi;

import java.io.Writer;
import java.io.PrintWriter;
import java.util.Vector;

/**
   * ThrowableInformation is log4j's internal representation of
   * throwables. It essentially consists of a string array, called
   * 'rep', where the first element, that is rep[0], represents the
   * string representation of the throwable (i.e. the value you get
   * when you do throwable.toString()) while subsequent elements
   * correspond the stack trace with the top most entry of the stack
   * corresponding to the second entry of the 'rep' array, that is
   * rep[1].
   *
   * @author Ceki G&uuml;lc&uuml;
   *
   * */
public class ThrowableInformation implements java.io.Serializable {

   static final long serialVersionUID = -4748765566864322735L;

   private transient Throwable throwable;  <--- this the most relevant line
   private String[] rep;

   public
   ThrowableInformation(Throwable throwable) {
     this.throwable = throwable;
   }

....
}

The solution to this problem is to enhance ThrowableInformation to
have a nestedThrowableInformation field that would contain
information about nested throwables.

The next question is whether we make these changes for log4j 1.2.7 or
log4j 1.3? (At some point I would like to stop working on 1.2). What
do you all think?

Another possible reaction to this problem is to say that nested
exception printing is the problem of the user. The user can always
extract the nested exception and print (log) that. As in,

   try {
     ....
   } catch(javax.ejb.EJBException ejbe) {
     logger.error("Got an EJBException. Root cause:", 
ejbe.getCausedByException());
   }

The problem is that while this will work locally, it will not work
after serialization. WAIT A MINUTE!  It will work after
serialization.


Thus, instead of a top-heavy approach (i.e. modifying
ThrowableInformation or WriterAppender), the user could write a log4j
wrapper that automatically extracted nested exceptions and logged
them...

Choices, choices, ....

>Delivered-To: ceki@qos.ch
>X-Authentication-Warning: costinm.sfo.covalent.net: costin owned process 
>doing -bs
>Date: Thu, 1 Aug 2002 20:53:42 -0700 (PDT)
>From: costinm@covalent.net
>X-X-Sender: costin@costinm.sfo.covalent.net
>To: Ceki G�lc� <ce...@qos.ch>
>Subject: Small patch to display nested exceptions
>
>Hi Ceki,
>
>Tomcat3.3 logger has the nice feature of displaying 'nested
>exceptions', which is extremely valuable in debugging. So does
>jdk1.4 logger.
>
>I couldn't find such thing in log4j - so I wrote a small patch
>( cut&paste from 33 logger ).
>
>Costin

--
Ceki