You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by Geoff Soutter <ge...@molten.com.au> on 2002/03/26 05:45:53 UTC

FYI/PATCH: Log4j bug masks part of Orion's stack traces

Hi there,

I've been having a weird problem with parts of my stack traces
disappearing.

After a few hours mucking around I've tracked it down to a bug in log4j
that I thought you may all wish to be aware of.

This shows up when you attempt to log an OrionRemoteException in an
application client which has been thrown from a session bean.

If I call System.out.printStackTrace() I get:

        at com.evermind.server.ejb.EJBUtils.getUserException(.:207)
        at
<mySessionBean>_StatelessSessionBeanWrapper3.<mySessionBeanMethod>(<mySe
ssionBean>_StatelessSessionBeanWrapper3.java:153)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.evermind._dq._fs(.:79)
        at com.evermind._bt.run(.:62)
at connection to localhost/127.0.0.1 as admin
        at
com.evermind._dn.EXCEPTION_ORIGINATES_FROM_THE_REMOTE_SERVER(.:1447)
        at com.evermind._dn.invokeMethod(.:1370)
        at com.evermind._yp.invoke(.:53)
        at __Proxy2.<mySessionBeanMethod>(Unknown Source)

But if I log the same exception through log4j I get only:

        at
com.evermind._dn.EXCEPTION_ORIGINATES_FROM_THE_REMOTE_SERVER(.:1447)
        at com.evermind._dn.invokeMethod(.:1370)
        at com.evermind._yp.invoke(.:53)
        at __Proxy2.<mySessionBeanMethod>(Unknown Source)

Turns out the reason for this is that there is a bug in the way log4j
deals with stack traces. In log4j, stace track formatting is handled by
a class called ThrowableInformation. It contains a subclass of
PrintWriter called VectorWriter which only overrides the println() - all
the other methods are effectively disabled. This class is passed into
Throwable.printStackTrace(). Unfortunately, Orion's implementation of
OrionRemoteException.printStackTrace() is calling print() rather than
println() to pass part of the remote part of the stack trace across.
Thus, this part of the stack trace is simply thrown away. Ouch.

This is a bug which impacts Orion and potentially any other user of
log4j which, in general, wishes to override the way that
printStackTrace() works. It has been reported before on the log4j
developers list
(http://www.mail-archive.com/log4j-dev@jakarta.apache.org/msg00926.html)
, but it appears Ceki is too busy to fix it :-).

Note, I'm using log4j 1.x at the moment but I had a quick check of the
CVS repository and it appears the bug is in latest stuff as well.

I created a simplistic new version of
ThrowableInformation.getThrowableStrRep(), which sucks the entire stack
trace into a buffer and then parses it into individual lines. It's
probably kinda slow compared to the old version, but at least it fixes
the bug. I've included it if you are interested.

  public
  String[] getThrowableStrRep() {
    if(rep != null) {
      return (String[]) rep.clone();
    } else {
      // NOTE: This is not particularly fast. This probably needs to be
      // re-architected to use JDK1.4's new parsed stack trace stuff
anyway,
      // so I consider this to be only a temporary solution.

      // First, obtain the _entire_ stack trace as a string
      CharArrayWriter caw = new CharArrayWriter();
      PrintWriter pw = new PrintWriter(caw);
      throwable.printStackTrace(pw);
      pw.flush();
      String trace = caw.toString();
      // Parse it into individual lines.
      // This should handle both Win32 and Unix EOL markers (hopefully).
      StringTokenizer tok = new StringTokenizer(trace, "\r\n");
      Vector v = new Vector();
      while (tok.hasMoreTokens()) {
          v.add(tok.nextToken());
      }
      // Convert the result into an array, without using an 1.2
functionality
      int len = v.size();
      rep = new String[len];
      for(int i = 0; i < len; i++) {
        rep[i] = (String) v.elementAt(i);
      }
      return rep;
    }
  }

Cheers

Geoff


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>


Re: FYI/PATCH: Log4j bug masks part of Orion's stack traces

Posted by Ceki Gülcü <ce...@qos.ch>.
Geoff,

It's a privilege to have one of the JSR47 experts on this list.

Thanks for the bug report. I have just added two new print functions in
ThrowableInformation.VectorWriter can you let me know if this solves the
problem with Orion?  I appreciate it, Ceki

At 15:45 26.03.2002 +1100, you wrote:
>Hi there,
>
>I've been having a weird problem with parts of my stack traces
>disappearing.
>
>After a few hours mucking around I've tracked it down to a bug in log4j
>that I thought you may all wish to be aware of.
>
>This shows up when you attempt to log an OrionRemoteException in an
>application client which has been thrown from a session bean.
>
>If I call System.out.printStackTrace() I get:
>
>         at com.evermind.server.ejb.EJBUtils.getUserException(.:207)
>         at
><mySessionBean>_StatelessSessionBeanWrapper3.<mySessionBeanMethod>(<mySe
>ssionBean>_StatelessSessionBeanWrapper3.java:153)
>         at java.lang.reflect.Method.invoke(Native Method)
>         at com.evermind._dq._fs(.:79)
>         at com.evermind._bt.run(.:62)
>at connection to localhost/127.0.0.1 as admin
>         at
>com.evermind._dn.EXCEPTION_ORIGINATES_FROM_THE_REMOTE_SERVER(.:1447)
>         at com.evermind._dn.invokeMethod(.:1370)
>         at com.evermind._yp.invoke(.:53)
>         at __Proxy2.<mySessionBeanMethod>(Unknown Source)
>
>But if I log the same exception through log4j I get only:
>
>         at
>com.evermind._dn.EXCEPTION_ORIGINATES_FROM_THE_REMOTE_SERVER(.:1447)
>         at com.evermind._dn.invokeMethod(.:1370)
>         at com.evermind._yp.invoke(.:53)
>         at __Proxy2.<mySessionBeanMethod>(Unknown Source)
>
>Turns out the reason for this is that there is a bug in the way log4j
>deals with stack traces. In log4j, stace track formatting is handled by
>a class called ThrowableInformation. It contains a subclass of
>PrintWriter called VectorWriter which only overrides the println() - all
>the other methods are effectively disabled. This class is passed into
>Throwable.printStackTrace(). Unfortunately, Orion's implementation of
>OrionRemoteException.printStackTrace() is calling print() rather than
>println() to pass part of the remote part of the stack trace across.
>Thus, this part of the stack trace is simply thrown away. Ouch.
>
>This is a bug which impacts Orion and potentially any other user of
>log4j which, in general, wishes to override the way that
>printStackTrace() works. It has been reported before on the log4j
>developers list
>(http://www.mail-archive.com/log4j-dev@jakarta.apache.org/msg00926.html)
>, but it appears Ceki is too busy to fix it :-).
>
>Note, I'm using log4j 1.x at the moment but I had a quick check of the
>CVS repository and it appears the bug is in latest stuff as well.
>
>I created a simplistic new version of
>ThrowableInformation.getThrowableStrRep(), which sucks the entire stack
>trace into a buffer and then parses it into individual lines. It's
>probably kinda slow compared to the old version, but at least it fixes
>the bug. I've included it if you are interested.
>
>   public
>   String[] getThrowableStrRep() {
>     if(rep != null) {
>       return (String[]) rep.clone();
>     } else {
>       // NOTE: This is not particularly fast. This probably needs to be
>       // re-architected to use JDK1.4's new parsed stack trace stuff
>anyway,
>       // so I consider this to be only a temporary solution.
>
>       // First, obtain the _entire_ stack trace as a string
>       CharArrayWriter caw = new CharArrayWriter();
>       PrintWriter pw = new PrintWriter(caw);
>       throwable.printStackTrace(pw);
>       pw.flush();
>       String trace = caw.toString();
>       // Parse it into individual lines.
>       // This should handle both Win32 and Unix EOL markers (hopefully).
>       StringTokenizer tok = new StringTokenizer(trace, "\r\n");
>       Vector v = new Vector();
>       while (tok.hasMoreTokens()) {
>           v.add(tok.nextToken());
>       }
>       // Convert the result into an array, without using an 1.2
>functionality
>       int len = v.size();
>       rep = new String[len];
>       for(int i = 0; i < len; i++) {
>         rep[i] = (String) v.elementAt(i);
>       }
>       return rep;
>     }
>   }
>
>Cheers
>
>Geoff

--
Ceki
My link of the month: http://java.sun.com/aboutJava/standardization/


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>