You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Thomas Tuft Muller <tt...@online.no> on 2001/12/14 12:01:56 UTC

ArrayIndexOutOfBoundsException in AsyncAppender

Hi,

This error inside the log4j API caused our server to hang (this trace was
logged in system.err.)

2001-12-14 10:07:28,735 - "java.lang.ArrayIndexOutOfBoundsException: 0 >= 0"
2001-12-14 10:07:28,735 - "	at java.util.Vector.elementAt(Vector.java:417)"
2001-12-14 10:07:28,745 - "	at
org.apache.log4j.spi.VectorWriter.toStringArray(ThrowableInformation.java:81
)"
2001-12-14 10:07:28,745 - "	at
org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(ThrowableInform
ation.java:43)"
2001-12-14 10:07:28,745 - "	at
org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent.java:217)"
2001-12-14 10:07:28,745 - "	at
org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:298)"
2001-12-14 10:07:28,745 - "	at
org.apache.log4j.CompositeRollingAppender.subAppend(CompositeRollingAppender
.java:341)"
2001-12-14 10:07:28,765 - "	at
org.apache.log4j.WriterAppender.append(WriterAppender.java:157)"
2001-12-14 10:07:28,765 - "	at
org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)"
2001-12-14 10:07:28,765 - "	at
org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(Append
erAttachableImpl.java:57)"
2001-12-14 10:07:28,765 - "	at
org.apache.log4j.Dispatcher.run(AsyncAppender.java:412)"

This is actually quite serious if we start to see it frequently.

Please find log4j.xml file attached.

Most likely the runtime error caused the async-appender thread to die. The
default implementation of ThreadGroup::uncaughtException dumps the
stacktrace to std err, exactly what happened here.

I dare to say that this is probably a deficiancy in the API. The async
appender is a variant of ActiveObject, and everything should be done to
ensure the stability of such an object. Instead of dying, it should log the
error/stacktrace via LogLog and continue (that is, if the error is not fatal
for the object itself or for the API as a whole).

Versions:
Log4j: 1.1.3
Java: java version "1.3.0"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-C)
Java HotSpot(TM) Server VM (build 2.0fcs-E, mixed mode)
OS: Win2k, service pack II

Any comments/ideas would be much appreciated.

--

Thomas














*************************************************************************
Copyright ERA Technology Ltd. 2001. (www.era.co.uk). All rights reserved. 
Confidential. No liability whatsoever is accepted for any loss or damage 
suffered as a result of accessing this message or any attachments.

RE: ArrayIndexOutOfBoundsException in AsyncAppender

Posted by Ceki Gulcu <ce...@qos.ch>.
Thomas,

I understand your position and apologize for the trouble this bug may
have caused. Let me note that such serious programming errors
(throwing runtime exceptions) have been extremely rare. In fact, if I
recall correctly, the most recent one was in September 2000, that is
over a year ago. If for some reason such bugs become common in log4j,
your proposal will be reconsidered. Regards, Ceki


At 20:51 16.12.2001 +0000, you wrote:
>Ceki,
>
>I respect your opinion, but in my case this error could possibly have
>brought down a mission-critiacal telephony system serving thousands of
>users.
>
>In general a logging library such as Log4j should be extremely conservative
>exposing bugs in a way that results in process failure and system hang. In
>case of internal errors it's primary concern should be to recover and
>continue working properly, but also (and this really goes without saying)
>have a generic way of reporting the error such that it's easy detectable and
>extractable. I assume that for Log4j LogLog and ErrorHandler exist for
>exactly those purposes.
>
>Regarding the Active Object pattern in general: I've written an abstract
>Active Object / TaskRunner library which I inter alia use in a general event
>handling system and for generic statemachines. There's no way acceptable
>that an error running a single task can cause the task runner to stop
>disgracefully. How such an error is propagated and reported, however, is
>another matter, and of course up to the Task implementor to conduct in a way
>that the error in question is not "placed behind a smoke screen and buried".
>
>Regards,
>
>--
>
>Thomas
>
>
>| -----Original Message-----
>| From: Ceki Gulcu [mailto:ceki@qos.ch]
>| Sent: 16 December 2001 11:31
>| To: Log4J Users List
>| Subject: RE: ArrayIndexOutOfBoundsException in AsyncAppender
>|
>|
>|
>| Thomas,
>|
>| This is a very interesting comment. I disagree with it for the
>| following reason. Wrapping the error in a try and catch block places
>| bugs behind a smoke screen effectively burying them, such that they
>| become much harder to detect. I do not fear bugs, only the insidious
>| ones.
>|
>| Consider the particular case of the ArrayIndexOutOfBoundsException
>| that you yourself reported. It took about 60 seconds to identify the
>| bug and propose a fix.  How many hours would it have taken if the code
>| was wrapped in a try catch block?  I think there is a valuable lesson to
>| be learned here. Regards, Ceki
>|
>| At 09:46 16.12.2001 +0000, you wrote:
>| >Thanx, Ceki.
>| >
>| >Again, allow me to suggest that the loop in Dispatcher is guarded by a
>| >try/catch block, thus preventing it from exiting disgracefully.
>| >
>| >--
>| >
>| >Thomas
>| >
>| >| -----Original Message-----
>| >| From: Ceki Gulcu [mailto:ceki@qos.ch]
>| >| Sent: 14 December 2001 22:11
>| >| To: Log4J Users List
>| >| Subject: Re: ArrayIndexOutOfBoundsException in AsyncAppender
>| >|
>| >|
>| >|
>| >| Thomas,
>| >|
>| >| Looks like a bug to me. Thanks for the info. The likely cause of
>| >| this problem is that the 'vw' static variable of type
>| >| VectorWriter is not accessed in a synchronized manner. You have
>| >| two threads trying to log an event containing an exception near
>| >| simultaneously.
>| >|
>| >| One easy solution is something like:
>| >|
>| >|   public
>| >|   String[] getThrowableStrRep() {
>| >|     if(rep != null) {
>| >|       return (String[]) rep.clone();
>| >|     } else {
>| >|       // BEGIN wrap by a synchronized block
>| >|       synchronized(vw) {
>| >|         throwable.printStackTrace(vw);
>| >|         rep = vw.toStringArray();
>| >|       }
>| >|       // END
>| >|       vw.clear();
>| >|       return rep;
>| >|     }
>| >|   }
>| >|
>| >| Thanks for the info. One other solution is to have the vw
>| >| variable as an instance variable instead of a static. As in:
>| >|
>| >|  private VectorWriter vw = new VectorWriter();
>| >|
>| >| instead of
>| >|
>| >|  static private VectorWriter vw = new VectorWriter();
>| >|
>| >| This second approach cleaner and I prefer it. Anyway, thanks for
>| >| the bug report. Regards, Ceki
>| >|
>| >| At 11:01 14.12.2001 +0000, you wrote:
>| >| >Hi,
>| >| >
>| >| >This error inside the log4j API caused our server to hang
>| (this trace was
>| >| >logged in system.err.)
>| >| >
>| >| >2001-12-14 10:07:28,735 -
>| >| "java.lang.ArrayIndexOutOfBoundsException: 0 >= 0"
>| >| >2001-12-14 10:07:28,735 - "     at
>| >| java.util.Vector.elementAt(Vector.java:417)"
>| >| >2001-12-14 10:07:28,745 - "     at
>| >| >org.apache.log4j.spi.VectorWriter.toStringArray(ThrowableInformat
>| >| ion.java:81
>| >| >)"
>| >| >2001-12-14 10:07:28,745 - "     at
>| >| >org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(Thro
>| >| wableInform
>| >| >ation.java:43)"
>| >| >2001-12-14 10:07:28,745 - "     at
>| >| >org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent
>| >| .java:217)"
>| >| >2001-12-14 10:07:28,745 - "     at
>| >| >org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:298)"
>| >| >2001-12-14 10:07:28,745 - "     at
>| >| >org.apache.log4j.CompositeRollingAppender.subAppend(CompositeRoll
>| >| ingAppender
>| >| >.java:341)"
>| >| >2001-12-14 10:07:28,765 - "     at
>| >| >org.apache.log4j.WriterAppender.append(WriterAppender.java:157)"
>| >| >2001-12-14 10:07:28,765 - "     at
>| >| >org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)"
>| >| >2001-12-14 10:07:28,765 - "     at
>| >| >org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppen
>| >| ders(Append
>| >| >erAttachableImpl.java:57)"
>| >| >2001-12-14 10:07:28,765 - "     at
>| >| >org.apache.log4j.Dispatcher.run(AsyncAppender.java:412)"
>| >| >
>| >| >This is actually quite serious if we start to see it frequently.
>| >| >
>| >| >Please find log4j.xml file attached.
>| >| >
>| >| >Most likely the runtime error caused the async-appender thread
>| >| to die. The
>| >| >default implementation of ThreadGroup::uncaughtException dumps the
>| >| >stacktrace to std err, exactly what happened here.
>| >| >
>| >| >I dare to say that this is probably a deficiancy in the API. The async
>| >| >appender is a variant of ActiveObject, and everything should
>| be done to
>| >| >ensure the stability of such an object. Instead of dying, it
>| >| should log the
>| >| >error/stacktrace via LogLog and continue (that is, if the error
>| >| is not fatal
>| >| >for the object itself or for the API as a whole).
>| >| >
>| >| >Versions:
>| >| >Log4j: 1.1.3
>| >| >Java: java version "1.3.0"
>| >| >Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-C)
>| >| >Java HotSpot(TM) Server VM (build 2.0fcs-E, mixed mode)
>| >| >OS: Win2k, service pack II
>| >| >
>| >| >Any comments/ideas would be much appreciated.
>| >| >
>| >| >--
>| >| >
>| >| >Thomas
>| >|
>| >|
>| >| --
>| >| To unsubscribe, e-mail:
>| >| <ma...@jakarta.apache.org>
>| >| For additional commands, e-mail:
>| >| <ma...@jakarta.apache.org>
>| >|
>| >|
>| >
>| >
>| >
>| >*************************************************************************
>| >Copyright ERA Technology Ltd. 2001. (www.era.co.uk). All rights
>| reserved.
>| >Confidential. No liability whatsoever is accepted for any loss or damage
>| >suffered as a result of accessing this message or any attachments.
>| >
>| >--
>| >To unsubscribe, e-mail:
>| <ma...@jakarta.apache.org>
>| >For additional commands, e-mail:
>| <ma...@jakarta.apache.org>
>|
>|
>| --
>| To unsubscribe, e-mail:
>| <ma...@jakarta.apache.org>
>| For additional commands, e-mail:
>| <ma...@jakarta.apache.org>
>|
>|
>
>
>--
>To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
>For additional commands, e-mail: <ma...@jakarta.apache.org>


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


RE: ArrayIndexOutOfBoundsException in AsyncAppender

Posted by Thomas Tuft Muller <tt...@online.no>.
Ceki,

I respect your opinion, but in my case this error could possibly have
brought down a mission-critiacal telephony system serving thousands of
users.

In general a logging library such as Log4j should be extremely conservative
exposing bugs in a way that results in process failure and system hang. In
case of internal errors it's primary concern should be to recover and
continue working properly, but also (and this really goes without saying)
have a generic way of reporting the error such that it's easy detectable and
extractable. I assume that for Log4j LogLog and ErrorHandler exist for
exactly those purposes.

Regarding the Active Object pattern in general: I've written an abstract
Active Object / TaskRunner library which I inter alia use in a general event
handling system and for generic statemachines. There's no way acceptable
that an error running a single task can cause the task runner to stop
disgracefully. How such an error is propagated and reported, however, is
another matter, and of course up to the Task implementor to conduct in a way
that the error in question is not "placed behind a smoke screen and buried".

Regards,

--

Thomas


| -----Original Message-----
| From: Ceki Gulcu [mailto:ceki@qos.ch]
| Sent: 16 December 2001 11:31
| To: Log4J Users List
| Subject: RE: ArrayIndexOutOfBoundsException in AsyncAppender
|
|
|
| Thomas,
|
| This is a very interesting comment. I disagree with it for the
| following reason. Wrapping the error in a try and catch block places
| bugs behind a smoke screen effectively burying them, such that they
| become much harder to detect. I do not fear bugs, only the insidious
| ones.
|
| Consider the particular case of the ArrayIndexOutOfBoundsException
| that you yourself reported. It took about 60 seconds to identify the
| bug and propose a fix.  How many hours would it have taken if the code
| was wrapped in a try catch block?  I think there is a valuable lesson to
| be learned here. Regards, Ceki
|
| At 09:46 16.12.2001 +0000, you wrote:
| >Thanx, Ceki.
| >
| >Again, allow me to suggest that the loop in Dispatcher is guarded by a
| >try/catch block, thus preventing it from exiting disgracefully.
| >
| >--
| >
| >Thomas
| >
| >| -----Original Message-----
| >| From: Ceki Gulcu [mailto:ceki@qos.ch]
| >| Sent: 14 December 2001 22:11
| >| To: Log4J Users List
| >| Subject: Re: ArrayIndexOutOfBoundsException in AsyncAppender
| >|
| >|
| >|
| >| Thomas,
| >|
| >| Looks like a bug to me. Thanks for the info. The likely cause of
| >| this problem is that the 'vw' static variable of type
| >| VectorWriter is not accessed in a synchronized manner. You have
| >| two threads trying to log an event containing an exception near
| >| simultaneously.
| >|
| >| One easy solution is something like:
| >|
| >|   public
| >|   String[] getThrowableStrRep() {
| >|     if(rep != null) {
| >|       return (String[]) rep.clone();
| >|     } else {
| >|       // BEGIN wrap by a synchronized block
| >|       synchronized(vw) {
| >|         throwable.printStackTrace(vw);
| >|         rep = vw.toStringArray();
| >|       }
| >|       // END
| >|       vw.clear();
| >|       return rep;
| >|     }
| >|   }
| >|
| >| Thanks for the info. One other solution is to have the vw
| >| variable as an instance variable instead of a static. As in:
| >|
| >|  private VectorWriter vw = new VectorWriter();
| >|
| >| instead of
| >|
| >|  static private VectorWriter vw = new VectorWriter();
| >|
| >| This second approach cleaner and I prefer it. Anyway, thanks for
| >| the bug report. Regards, Ceki
| >|
| >| At 11:01 14.12.2001 +0000, you wrote:
| >| >Hi,
| >| >
| >| >This error inside the log4j API caused our server to hang
| (this trace was
| >| >logged in system.err.)
| >| >
| >| >2001-12-14 10:07:28,735 -
| >| "java.lang.ArrayIndexOutOfBoundsException: 0 >= 0"
| >| >2001-12-14 10:07:28,735 - "     at
| >| java.util.Vector.elementAt(Vector.java:417)"
| >| >2001-12-14 10:07:28,745 - "     at
| >| >org.apache.log4j.spi.VectorWriter.toStringArray(ThrowableInformat
| >| ion.java:81
| >| >)"
| >| >2001-12-14 10:07:28,745 - "     at
| >| >org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(Thro
| >| wableInform
| >| >ation.java:43)"
| >| >2001-12-14 10:07:28,745 - "     at
| >| >org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent
| >| .java:217)"
| >| >2001-12-14 10:07:28,745 - "     at
| >| >org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:298)"
| >| >2001-12-14 10:07:28,745 - "     at
| >| >org.apache.log4j.CompositeRollingAppender.subAppend(CompositeRoll
| >| ingAppender
| >| >.java:341)"
| >| >2001-12-14 10:07:28,765 - "     at
| >| >org.apache.log4j.WriterAppender.append(WriterAppender.java:157)"
| >| >2001-12-14 10:07:28,765 - "     at
| >| >org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)"
| >| >2001-12-14 10:07:28,765 - "     at
| >| >org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppen
| >| ders(Append
| >| >erAttachableImpl.java:57)"
| >| >2001-12-14 10:07:28,765 - "     at
| >| >org.apache.log4j.Dispatcher.run(AsyncAppender.java:412)"
| >| >
| >| >This is actually quite serious if we start to see it frequently.
| >| >
| >| >Please find log4j.xml file attached.
| >| >
| >| >Most likely the runtime error caused the async-appender thread
| >| to die. The
| >| >default implementation of ThreadGroup::uncaughtException dumps the
| >| >stacktrace to std err, exactly what happened here.
| >| >
| >| >I dare to say that this is probably a deficiancy in the API. The async
| >| >appender is a variant of ActiveObject, and everything should
| be done to
| >| >ensure the stability of such an object. Instead of dying, it
| >| should log the
| >| >error/stacktrace via LogLog and continue (that is, if the error
| >| is not fatal
| >| >for the object itself or for the API as a whole).
| >| >
| >| >Versions:
| >| >Log4j: 1.1.3
| >| >Java: java version "1.3.0"
| >| >Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-C)
| >| >Java HotSpot(TM) Server VM (build 2.0fcs-E, mixed mode)
| >| >OS: Win2k, service pack II
| >| >
| >| >Any comments/ideas would be much appreciated.
| >| >
| >| >--
| >| >
| >| >Thomas
| >|
| >|
| >| --
| >| To unsubscribe, e-mail:
| >| <ma...@jakarta.apache.org>
| >| For additional commands, e-mail:
| >| <ma...@jakarta.apache.org>
| >|
| >|
| >
| >
| >
| >*************************************************************************
| >Copyright ERA Technology Ltd. 2001. (www.era.co.uk). All rights
| reserved.
| >Confidential. No liability whatsoever is accepted for any loss or damage
| >suffered as a result of accessing this message or any attachments.
| >
| >--
| >To unsubscribe, e-mail:
| <ma...@jakarta.apache.org>
| >For additional commands, e-mail:
| <ma...@jakarta.apache.org>
|
|
| --
| To unsubscribe, e-mail:
| <ma...@jakarta.apache.org>
| For additional commands, e-mail:
| <ma...@jakarta.apache.org>
|
|


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


RE: ArrayIndexOutOfBoundsException in AsyncAppender

Posted by Ceki Gulcu <ce...@qos.ch>.
Thomas,

This is a very interesting comment. I disagree with it for the
following reason. Wrapping the error in a try and catch block places
bugs behind a smoke screen effectively burying them, such that they
become much harder to detect. I do not fear bugs, only the insidious
ones.

Consider the particular case of the ArrayIndexOutOfBoundsException
that you yourself reported. It took about 60 seconds to identify the
bug and propose a fix.  How many hours would it have taken if the code
was wrapped in a try catch block?  I think there is a valuable lesson to
be learned here. Regards, Ceki

At 09:46 16.12.2001 +0000, you wrote:
>Thanx, Ceki.
>
>Again, allow me to suggest that the loop in Dispatcher is guarded by a
>try/catch block, thus preventing it from exiting disgracefully.
>
>--
>
>Thomas
>
>| -----Original Message-----
>| From: Ceki Gulcu [mailto:ceki@qos.ch]
>| Sent: 14 December 2001 22:11
>| To: Log4J Users List
>| Subject: Re: ArrayIndexOutOfBoundsException in AsyncAppender
>|
>|
>|
>| Thomas,
>|
>| Looks like a bug to me. Thanks for the info. The likely cause of
>| this problem is that the 'vw' static variable of type
>| VectorWriter is not accessed in a synchronized manner. You have
>| two threads trying to log an event containing an exception near
>| simultaneously.
>|
>| One easy solution is something like:
>|
>|   public
>|   String[] getThrowableStrRep() {
>|     if(rep != null) {
>|       return (String[]) rep.clone();
>|     } else {
>|       // BEGIN wrap by a synchronized block
>|       synchronized(vw) {
>|         throwable.printStackTrace(vw);
>|         rep = vw.toStringArray();
>|       }
>|       // END
>|       vw.clear();
>|       return rep;
>|     }
>|   }
>|
>| Thanks for the info. One other solution is to have the vw
>| variable as an instance variable instead of a static. As in:
>|
>|  private VectorWriter vw = new VectorWriter();
>|
>| instead of
>|
>|  static private VectorWriter vw = new VectorWriter();
>|
>| This second approach cleaner and I prefer it. Anyway, thanks for
>| the bug report. Regards, Ceki
>|
>| At 11:01 14.12.2001 +0000, you wrote:
>| >Hi,
>| >
>| >This error inside the log4j API caused our server to hang (this trace was
>| >logged in system.err.)
>| >
>| >2001-12-14 10:07:28,735 -
>| "java.lang.ArrayIndexOutOfBoundsException: 0 >= 0"
>| >2001-12-14 10:07:28,735 - "     at
>| java.util.Vector.elementAt(Vector.java:417)"
>| >2001-12-14 10:07:28,745 - "     at
>| >org.apache.log4j.spi.VectorWriter.toStringArray(ThrowableInformat
>| ion.java:81
>| >)"
>| >2001-12-14 10:07:28,745 - "     at
>| >org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(Thro
>| wableInform
>| >ation.java:43)"
>| >2001-12-14 10:07:28,745 - "     at
>| >org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent
>| .java:217)"
>| >2001-12-14 10:07:28,745 - "     at
>| >org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:298)"
>| >2001-12-14 10:07:28,745 - "     at
>| >org.apache.log4j.CompositeRollingAppender.subAppend(CompositeRoll
>| ingAppender
>| >.java:341)"
>| >2001-12-14 10:07:28,765 - "     at
>| >org.apache.log4j.WriterAppender.append(WriterAppender.java:157)"
>| >2001-12-14 10:07:28,765 - "     at
>| >org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)"
>| >2001-12-14 10:07:28,765 - "     at
>| >org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppen
>| ders(Append
>| >erAttachableImpl.java:57)"
>| >2001-12-14 10:07:28,765 - "     at
>| >org.apache.log4j.Dispatcher.run(AsyncAppender.java:412)"
>| >
>| >This is actually quite serious if we start to see it frequently.
>| >
>| >Please find log4j.xml file attached.
>| >
>| >Most likely the runtime error caused the async-appender thread
>| to die. The
>| >default implementation of ThreadGroup::uncaughtException dumps the
>| >stacktrace to std err, exactly what happened here.
>| >
>| >I dare to say that this is probably a deficiancy in the API. The async
>| >appender is a variant of ActiveObject, and everything should be done to
>| >ensure the stability of such an object. Instead of dying, it
>| should log the
>| >error/stacktrace via LogLog and continue (that is, if the error
>| is not fatal
>| >for the object itself or for the API as a whole).
>| >
>| >Versions:
>| >Log4j: 1.1.3
>| >Java: java version "1.3.0"
>| >Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-C)
>| >Java HotSpot(TM) Server VM (build 2.0fcs-E, mixed mode)
>| >OS: Win2k, service pack II
>| >
>| >Any comments/ideas would be much appreciated.
>| >
>| >--
>| >
>| >Thomas
>|
>|
>| --
>| To unsubscribe, e-mail:
>| <ma...@jakarta.apache.org>
>| For additional commands, e-mail:
>| <ma...@jakarta.apache.org>
>|
>|
>
>
>
>*************************************************************************
>Copyright ERA Technology Ltd. 2001. (www.era.co.uk). All rights reserved. 
>Confidential. No liability whatsoever is accepted for any loss or damage 
>suffered as a result of accessing this message or any attachments.
>
>--
>To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
>For additional commands, e-mail: <ma...@jakarta.apache.org>


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


RE: ArrayIndexOutOfBoundsException in AsyncAppender

Posted by Thomas Tuft Muller <tt...@online.no>.
Thanx, Ceki.

Again, allow me to suggest that the loop in Dispatcher is guarded by a
try/catch block, thus preventing it from exiting disgracefully.

--

Thomas

| -----Original Message-----
| From: Ceki Gulcu [mailto:ceki@qos.ch]
| Sent: 14 December 2001 22:11
| To: Log4J Users List
| Subject: Re: ArrayIndexOutOfBoundsException in AsyncAppender
|
|
|
| Thomas,
|
| Looks like a bug to me. Thanks for the info. The likely cause of
| this problem is that the 'vw' static variable of type
| VectorWriter is not accessed in a synchronized manner. You have
| two threads trying to log an event containing an exception near
| simultaneously.
|
| One easy solution is something like:
|
|   public
|   String[] getThrowableStrRep() {
|     if(rep != null) {
|       return (String[]) rep.clone();
|     } else {
|       // BEGIN wrap by a synchronized block
|       synchronized(vw) {
|         throwable.printStackTrace(vw);
|         rep = vw.toStringArray();
|       }
|       // END
|       vw.clear();
|       return rep;
|     }
|   }
|
| Thanks for the info. One other solution is to have the vw
| variable as an instance variable instead of a static. As in:
|
|  private VectorWriter vw = new VectorWriter();
|
| instead of
|
|  static private VectorWriter vw = new VectorWriter();
|
| This second approach cleaner and I prefer it. Anyway, thanks for
| the bug report. Regards, Ceki
|
| At 11:01 14.12.2001 +0000, you wrote:
| >Hi,
| >
| >This error inside the log4j API caused our server to hang (this trace was
| >logged in system.err.)
| >
| >2001-12-14 10:07:28,735 -
| "java.lang.ArrayIndexOutOfBoundsException: 0 >= 0"
| >2001-12-14 10:07:28,735 - "     at
| java.util.Vector.elementAt(Vector.java:417)"
| >2001-12-14 10:07:28,745 - "     at
| >org.apache.log4j.spi.VectorWriter.toStringArray(ThrowableInformat
| ion.java:81
| >)"
| >2001-12-14 10:07:28,745 - "     at
| >org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(Thro
| wableInform
| >ation.java:43)"
| >2001-12-14 10:07:28,745 - "     at
| >org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent
| .java:217)"
| >2001-12-14 10:07:28,745 - "     at
| >org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:298)"
| >2001-12-14 10:07:28,745 - "     at
| >org.apache.log4j.CompositeRollingAppender.subAppend(CompositeRoll
| ingAppender
| >.java:341)"
| >2001-12-14 10:07:28,765 - "     at
| >org.apache.log4j.WriterAppender.append(WriterAppender.java:157)"
| >2001-12-14 10:07:28,765 - "     at
| >org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)"
| >2001-12-14 10:07:28,765 - "     at
| >org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppen
| ders(Append
| >erAttachableImpl.java:57)"
| >2001-12-14 10:07:28,765 - "     at
| >org.apache.log4j.Dispatcher.run(AsyncAppender.java:412)"
| >
| >This is actually quite serious if we start to see it frequently.
| >
| >Please find log4j.xml file attached.
| >
| >Most likely the runtime error caused the async-appender thread
| to die. The
| >default implementation of ThreadGroup::uncaughtException dumps the
| >stacktrace to std err, exactly what happened here.
| >
| >I dare to say that this is probably a deficiancy in the API. The async
| >appender is a variant of ActiveObject, and everything should be done to
| >ensure the stability of such an object. Instead of dying, it
| should log the
| >error/stacktrace via LogLog and continue (that is, if the error
| is not fatal
| >for the object itself or for the API as a whole).
| >
| >Versions:
| >Log4j: 1.1.3
| >Java: java version "1.3.0"
| >Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-C)
| >Java HotSpot(TM) Server VM (build 2.0fcs-E, mixed mode)
| >OS: Win2k, service pack II
| >
| >Any comments/ideas would be much appreciated.
| >
| >--
| >
| >Thomas
|
|
| --
| To unsubscribe, e-mail:
| <ma...@jakarta.apache.org>
| For additional commands, e-mail:
| <ma...@jakarta.apache.org>
|
|



*************************************************************************
Copyright ERA Technology Ltd. 2001. (www.era.co.uk). All rights reserved. 
Confidential. No liability whatsoever is accepted for any loss or damage 
suffered as a result of accessing this message or any attachments.

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


Re: ArrayIndexOutOfBoundsException in AsyncAppender

Posted by Ceki Gulcu <ce...@qos.ch>.
Thomas,

Looks like a bug to me. Thanks for the info. The likely cause of this problem is that the 'vw' static variable of type VectorWriter is not accessed in a synchronized manner. You have two threads trying to log an event containing an exception near simultaneously. 

One easy solution is something like:

  public
  String[] getThrowableStrRep() {
    if(rep != null) {
      return (String[]) rep.clone();
    } else {
      // BEGIN wrap by a synchronized block
      synchronized(vw) {
        throwable.printStackTrace(vw);     
        rep = vw.toStringArray();
      } 
      // END
      vw.clear();
      return rep;
    }
  }

Thanks for the info. One other solution is to have the vw variable as an instance variable instead of a static. As in:

 private VectorWriter vw = new VectorWriter();
 
instead of

 static private VectorWriter vw = new VectorWriter();
 
This second approach cleaner and I prefer it. Anyway, thanks for the bug report. Regards, Ceki

At 11:01 14.12.2001 +0000, you wrote:
>Hi,
>
>This error inside the log4j API caused our server to hang (this trace was
>logged in system.err.)
>
>2001-12-14 10:07:28,735 - "java.lang.ArrayIndexOutOfBoundsException: 0 >= 0"
>2001-12-14 10:07:28,735 - "     at java.util.Vector.elementAt(Vector.java:417)"
>2001-12-14 10:07:28,745 - "     at
>org.apache.log4j.spi.VectorWriter.toStringArray(ThrowableInformation.java:81
>)"
>2001-12-14 10:07:28,745 - "     at
>org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(ThrowableInform
>ation.java:43)"
>2001-12-14 10:07:28,745 - "     at
>org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent.java:217)"
>2001-12-14 10:07:28,745 - "     at
>org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:298)"
>2001-12-14 10:07:28,745 - "     at
>org.apache.log4j.CompositeRollingAppender.subAppend(CompositeRollingAppender
>.java:341)"
>2001-12-14 10:07:28,765 - "     at
>org.apache.log4j.WriterAppender.append(WriterAppender.java:157)"
>2001-12-14 10:07:28,765 - "     at
>org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)"
>2001-12-14 10:07:28,765 - "     at
>org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(Append
>erAttachableImpl.java:57)"
>2001-12-14 10:07:28,765 - "     at
>org.apache.log4j.Dispatcher.run(AsyncAppender.java:412)"
>
>This is actually quite serious if we start to see it frequently.
>
>Please find log4j.xml file attached.
>
>Most likely the runtime error caused the async-appender thread to die. The
>default implementation of ThreadGroup::uncaughtException dumps the
>stacktrace to std err, exactly what happened here.
>
>I dare to say that this is probably a deficiancy in the API. The async
>appender is a variant of ActiveObject, and everything should be done to
>ensure the stability of such an object. Instead of dying, it should log the
>error/stacktrace via LogLog and continue (that is, if the error is not fatal
>for the object itself or for the API as a whole).
>
>Versions:
>Log4j: 1.1.3
>Java: java version "1.3.0"
>Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.0-C)
>Java HotSpot(TM) Server VM (build 2.0fcs-E, mixed mode)
>OS: Win2k, service pack II
>
>Any comments/ideas would be much appreciated.
>
>--
>
>Thomas


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