----------------------------------------------------------------
BEFORE YOU POST, search the faq at <http://java.apache.org/faq/>
WHEN YOU POST, include all relevant version numbers, log files,
and configuration files. Don't make us guess your problem!!!
----------------------------------------------------------------
I first tried submitting this bug using the web interface, but it complained
that all the fields were blank. (No idea why... long forms perhaps? Happened
in Netscape, IE and Mozilla.) I then posted the following to the developers
list, but I haven't seen any responses. I'm hoping I may have more luck
here.
Apache+Apache JServ release:
Apache-1.3.9-4/1.3.11, Jserv 1.0 and 1.1
Class: sw-bug
Severity: serious
Environment:
Seen on Linux (i386 RedHat 6.1, JDK1.2.2-RC4, Apache 1.3.9-4, Jserv 1.1-2)
and Solaris (JDK1.2.2-001+Hotspot, Apache 1.3.11, Jserv 1.0)
Synopsis: LogWriter.flush creates unnecessary threads under load
Full description:
LogWriter's flush mechanism creates a new thread to flush the
log to disk if the buffer is too large. Unfortunately, under load that
new thread may never get to run, so the next time flush is called (which will
be on the next logging attempt), another new thread will be created, etc.
(The problem is less severe on Jserv 1.1 where the first thing the flush thread
does is to set itself to maximum priority, but it needs to get that far first.)
On Solaris with an enterprise servlet I have seen this repeatably cause
Java to run out of memory after Jserv created over 2000 threads in a few
seconds. (This may have been because the Agent's thread managed to get in
for long enough to complain that the log queue age had been exceeded... causing
a write, which caused a flush, etc.)
As a corollary, I've also seen an IndexOutOfBoundsException in LogWriter.Agent,
as the flush method in there is unsynchronized. In other words, two threads may
be in the following method at the same time:
public void flush()
{
while(!logQueue.isEmpty())
{
LogRecord logrecord = (LogRecord)logQueue.get();
if(logrecord != null)
write(logrecord);
}
}
This clearly causes a problem if two threads get past the !logQueue.isEmpty()
test when there's only one record left. It also means that logs could end up
out of order, as you could have a
Thread 1 Thread 2
get
get
write
write
situation.
How can we repeat this problem?:
The following servlet manages to get my linux box up to load fairly easily,
although you may need to have a few browser windows running the code, depending
on the strength of your machine:
import java.io.*;
import javax.servlet.*;
import javax.servlet.http.*;
import java.util.*;
public class Hello extends HttpServlet
{
public void doGet (HttpServletRequest request,
HttpServletResponse response)
throws ServletException, IOException
{
PrintWriter out = response.getWriter();
response.setContentType ("text/html");
out.println ("<html><body><h1>Hello</h1></body></html>");
Thread eater = new Thread (new Hungry());
eater.start();
for (int i=0; i < 5000; i++)
log ("Log "+i);
out.close();
}
class Hungry implements Runnable
{
public void run()
{
Thread.currentThread().setPriority(2);
/* Run hungrily for 20 seconds */
long start = System.currentTimeMillis();
long x=2;
while (System.currentTimeMillis()<start+20*1000 &&
x != 0)
{
// Give it some actual work
x = x*x;
if (x > 1000)
x=2;
}
}
}
}
To see the threads being created, I modified org.apache.java.io.LogWriter to
contain the following code:
static int going=0;
static PrintStream plumblog;
static
{
try
{
plumblog = new PrintStream (new FileOutputStream
("/home/jon/servlets/plumb.log");
plumblog.println ("Plumbing log: "+new Date());
}
catch (IOException e)
{
}
}
public static synchronized void incGoing ()
{
going++;
plumblog.println (new Date()+" Starting plumber: "+going+" currently ru$
}
public static synchronized void decGoing ()
{
going--;
plumblog.println (new Date()+" Stopping plumber: "+going+" currently ru$
}
public void flush()
{
if(logDaemon != null)
{
Runnable runnable = new Runnable() {
public void run()
{
Thread.currentThread().setPriority(10);
logDaemon.flush();
LogWriter.decGoing();
}
};
LogWriter.incGoing();
(new Thread(runnable)).start();
}
}
Run tail -f on the plumbing log, and you will (hopefully) see a log of
threads being created when the system is under load and logs are being written.
Do you have any suggested way to fix it?:
Perhaps something like:
Thread flushThread=null;
public void flush()
{
if (logDaemon==null)
return;
synchronized (this)
{
if (flushThread!=null)
return;
flushThread = new Thread (new Runnable ()
{
public void run()
{
Thread.currentThread().setPriority (Thread.MAX_PRIORITY);
logDaemon.flush();
flushThreadStopped();
}
});
flushThread.start();
}
}
synchronized flushThreadStopped ()
{
flushThread=null;
}
This would at least improve matters, if not entirely cure them, I believe.
It certainly seems to have worked when I tried it, in that it only creates
one thread. However, I believe LogWriter.Agent can also run its flush routine
as well, so perhaps LogWriter.Agent.flush should be synchronized.
Jon
--
--------------------------------------------------------------
Please read the FAQ! <http://java.apache.org/faq/>
To subscribe: [EMAIL PROTECTED]
To unsubscribe: [EMAIL PROTECTED]
Archives and Other: <http://java.apache.org/main/mail.html>
Problems?: [EMAIL PROTECTED]
