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 "Millard, Ray" <RM...@Aegonusa.com> on 2001/08/15 20:08:22 UTC

Bug in NDC::lazyRemove??

I have been researching the implementation of NDC::remove and
NDC::lazyRemove.  I think that I may have found a bug in the implementation
of NDC::lazyRemove, however, I may be missing something.

I wanted to know how often the main clean up portion of NDC::lazyRemove was
to be executed.  From the code, I see that NDC::lazyRemove is only called by
NDC::remove.  NDC::remove calls NDC::lazyRemove every time it is called.  I
believe that the implementation of lazyRemove is intended to have the main
clean up portion run only every sixth time it is called, however, I believe
that the "if" statement controlling this is wrong.  Here is the source code
from NDC::lazyRemove

private
  static
  void lazyRemove() {
     
    // The synchronization on ht is necessary to prevent JDK 1.2.x from
    // throwing ConcurrentModificationExceptions at us. This sucks BIG-TIME.
    // One solution is to write our own hashtable implementation.
    Vector v;
    
    synchronized(ht) {
      // Avoid calling clean-up too often.
      if(++pushCounter >= REAP_THRESHOLD) {
	return; // We release the lock ASAP.
      } else {
	pushCounter = 0; // OK let's do some work.
      }

      int misses = 0;
      v = new Vector(); 
      Enumeration enum = ht.keys();
      // We give up after 4 straigt missses. That is 4 consecutive
      // inspected threads in 'ht' that turn out to be alive.
      // The higher the proportion on dead threads in ht, the higher the
      // chances of removal.
      while(enum.hasMoreElements() && (misses <= 4)) {
	Thread t = (Thread) enum.nextElement();
	if(t.isAlive()) {
	  misses++;
	} else {
	  misses = 0;
	  v.addElement(t);
	}
      }
    } // synchronized

    int size = v.size();
    for(int i = 0; i < size; i++) {
      Thread t = (Thread) v.elementAt(i);
      LogLog.debug("Lazy NDC removal for thread [" + t.getName() + "] ("+ 
		   ht.size() + ").");
      ht.remove(t);
    }
  }

The if statement is executed only  if pushCounter is >=   REAP_THRESHOLD  

<<<<<  if(++pushCounter >= REAP_THRESHOLD) {   >>>>>>

however, pushCounter is initialized to 0 and only ever incremented here.
REAP_THRESHOLD is initialized to 5, and never modified (it is static final).
The first time NDC::lazyRemove is called, pushCounter will be 0.  Since 0 is
less than 5, the else statement is executed.  The else statement then sets
pushCounter back to 0, so that every time lazyRemove is called, pushCounter
is always 0, meaning that the clean up code is ALWAYS executed, not every
sixth time.

Is the if statement supposed to be less than or equal to instead of greater
than or equal to, like this <<<<<<<<<  if(++pushCounter <= REAP_THRESHOLD) {
>>>>>?

Thoughts?????





---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: log4j-user-help@jakarta.apache.org


Re: Bug in NDC::lazyRemove??

Posted by Ceki Gülcü <cg...@qos.ch>.
Ray,

Indeed, it's a performance bug which unfortunately happen to be my speciality. Fortunately, this one was already caught by Dan Milstein and corrected in the latest code in our CVS rep. Thanks for reporting it tough. Cheers, Ceki

At 13:08 15.08.2001 -0500, Millard, Ray wrote:
>I have been researching the implementation of NDC::remove and
>NDC::lazyRemove.  I think that I may have found a bug in the implementation
>of NDC::lazyRemove, however, I may be missing something.
>
>I wanted to know how often the main clean up portion of NDC::lazyRemove was
>to be executed.  From the code, I see that NDC::lazyRemove is only called by
>NDC::remove.  NDC::remove calls NDC::lazyRemove every time it is called.  I
>believe that the implementation of lazyRemove is intended to have the main
>clean up portion run only every sixth time it is called, however, I believe
>that the "if" statement controlling this is wrong.  Here is the source code
>from NDC::lazyRemove
>
>private
>  static
>  void lazyRemove() {
>     
>    // The synchronization on ht is necessary to prevent JDK 1.2.x from
>    // throwing ConcurrentModificationExceptions at us. This sucks BIG-TIME.
>    // One solution is to write our own hashtable implementation.
>    Vector v;
>    
>    synchronized(ht) {
>      // Avoid calling clean-up too often.
>      if(++pushCounter >= REAP_THRESHOLD) {
>        return; // We release the lock ASAP.
>      } else {
>        pushCounter = 0; // OK let's do some work.
>      }
>
>      int misses = 0;
>      v = new Vector(); 
>      Enumeration enum = ht.keys();
>      // We give up after 4 straigt missses. That is 4 consecutive
>      // inspected threads in 'ht' that turn out to be alive.
>      // The higher the proportion on dead threads in ht, the higher the
>      // chances of removal.
>      while(enum.hasMoreElements() && (misses <= 4)) {
>        Thread t = (Thread) enum.nextElement();
>        if(t.isAlive()) {
>          misses++;
>        } else {
>          misses = 0;
>          v.addElement(t);
>        }
>      }
>    } // synchronized
>
>    int size = v.size();
>    for(int i = 0; i < size; i++) {
>      Thread t = (Thread) v.elementAt(i);
>      LogLog.debug("Lazy NDC removal for thread [" + t.getName() + "] ("+ 
>                   ht.size() + ").");
>      ht.remove(t);
>    }
>  }
>
>The if statement is executed only  if pushCounter is >=   REAP_THRESHOLD  
>
><<<<<  if(++pushCounter >= REAP_THRESHOLD) {   >>>>>>
>
>however, pushCounter is initialized to 0 and only ever incremented here.
>REAP_THRESHOLD is initialized to 5, and never modified (it is static final).
>The first time NDC::lazyRemove is called, pushCounter will be 0.  Since 0 is
>less than 5, the else statement is executed.  The else statement then sets
>pushCounter back to 0, so that every time lazyRemove is called, pushCounter
>is always 0, meaning that the clean up code is ALWAYS executed, not every
>sixth time.
>
>Is the if statement supposed to be less than or equal to instead of greater
>than or equal to, like this <<<<<<<<<  if(++pushCounter <= REAP_THRESHOLD) {
>>>>>>?
>
>Thoughts?????
>
>
>
>
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: log4j-user-unsubscribe@jakarta.apache.org
>For additional commands, e-mail: log4j-user-help@jakarta.apache.org

--
Ceki Gülcü - http://qos.ch


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: log4j-user-help@jakarta.apache.org