You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cocoon.apache.org by Robin Green <gr...@hotmail.com> on 2000/08/24 21:08:44 UTC
[PATCH] [1.8] Optional profiler, and fixes for overzealous synchronization
Oops. With the attachment this time.
Four patches in one here. More coming this weekend hopefully (but I always
say that, and never deliver... :)
1. The cocoon 1.8-dev pipeline is now essentially single-threaded (per
Engine, which means per servlet context). This was added with the blocking
changes in the latest version of Engine.java, but it doesn't make sense. The
new system of blocking per page should be quite adequate for efficiency - no
need to hold up a whole site because of one slow page (perhaps a page which
gets data from an external source) - and in fact blocking a whole site makes
blocking individual pages totally redundant, so it doesn't make sense in
that way either.
2. Synchronization on wait() and notify() isn't a pointless bureaucratic
demand - it is explictly required because it requires a little bit of
thought. Synchronization is meant to be wide enough to prevent missed
notifications - and in the case of inner class Block a missed notification
could occur, causing a hang on a request. Imagine that the lock method was
called, and a context switch (i.e. switch to another thread) occured on the
line
System.err.println( "Blocking: " + key );
whereupon another thread removed the key and called notifyAll(). In this
scenario the first thread would miss the notification and would block
forever. (Of course, the bug mentioned above means that this bug would never
occur in the current release.)
3. The profiler class (in attached newfiles.zip) can be used to record the
time taken by each class in the pipeline for any request. A very simple
samples/profiler/profiler.xml and profile.xsl (in attached zip) can be used
to view the results. The profiling is off by default, and can be enabled by
uncommenting
#profiler.enabled=true
in the (updated) cocoon.properties file. Obviously, it needs Engine.java to
be modified, as below, for it to be able to record.
We have found it quite useful to see the length of time taken by each stage
- it seems that a stylesheet with a linear-to-tabular conversion (i.e.
splitting into blocks of 5) and with an xsl:import takes 2.5 seconds - as
opposed to 0.5 seconds for a standard stylesheet - on our very slow test
machine. Now to find out which of those is causing the difference!
NOTE: Feel free to change the com.itao.xml packagename for DOMWriter.
4. Rationalisation of global and request options in Engine.java. A couple of
people have requested to turn off the VERBOSE option without rebuilding
Cocoon. Well now you can - and you can control it per request, as well.
--- Defaults.old Thu Aug 24 14:55:36 2000
+++ Defaults.java Thu Aug 24 17:33:08 2000
@@ -83,6 +83,8 @@
public static final String CACHE_DEFAULT =
"org.apache.cocoon.cache.CocoonCache";
public static final String STORE_PROP = "store";
public static final String STORE_DEFAULT =
"org.apache.cocoon.store.CocoonStore";
+ public static final String PROFILER_PROP = "profiler";
+ public static final String PROFILER_DEFAULT =
"org.apache.cocoon.Profiler";
public static final String PRODUCER_PROP = "producer";
public static final String PROCESSOR_PROP = "processor";
@@ -98,7 +100,9 @@
public static final int LOOPS = 10;
- public static final boolean VERBOSE = @verbose@;
public static final boolean LOG = @log@;
+ // Profiler event types. These need to be valid XML names - no spaces.
+ public static final String WHOLE_REQUEST = "Whole-request",
+ OUTPUTTING = "Outputting";
}
--- Engine.old Thu Aug 24 14:53:44 2000
+++ Engine.java Thu Aug 24 18:43:00 2000
@@ -80,7 +80,8 @@
public class Engine implements Defaults {
private Block blocker = new Block();
-
+ private boolean VERBOSE, PROFILE;
+
private static Hashtable engineInstances = new Hashtable(1, 0.90f);
Configurations configurations;
@@ -99,6 +100,7 @@
Cache cache;
Store store;
Logger logger;
+ Profiler profiler;
ServletContext servletContext;
@@ -181,6 +183,16 @@
"org.apache.cocoon.Browsers",
configurations.getConfigurations(BROWSERS_PROP));
manager.setRole("browsers", browsers);
+
+ VERBOSE = configurations.get ("verbosity", "true").equals ("true");
+
+ // If enabled, create the profiler and register it
+ PROFILE = configurations.get ("profiler.enabled", "false").equals
("true");
+ if (PROFILE) {
+ profiler = (Profiler) manager.create((String)
configurations.get(PROFILER_PROP,
+ PROFILER_DEFAULT),
configurations.getConfigurations(PROFILER_PROP));
+ manager.setRole("profiler", profiler);
+ }
}
/**
@@ -199,7 +211,7 @@
public static Engine getInstance(Configurations confs, Object context)
throws Exception {
Engine engine = (Engine) engineInstances.get(context);
-
+
if (engine == null) {
synchronized (Engine.class) {
engine = new Engine(confs, context);
@@ -224,7 +236,7 @@
// return the first engine instance found
return (Engine) engineInstances.elements().nextElement();
}
-
+
throw new Exception("The Cocoon engine has not been initialized!");
}
@@ -234,6 +246,20 @@
*/
public void handle(HttpServletRequest request, HttpServletResponse
response) throws Exception {
+ // get the request flags
+ boolean CACHE = getFlag(request, "cache", true);
+ boolean DEBUG = getFlag(request, "debug", false);
+ boolean VERBOSE = getFlag(request, "verbose", this.VERBOSE);
+ boolean PROFILE = getFlag(request, "profile", this.PROFILE);
+
+ Profiler.RequestMarker requestMarker = null;
+ if (PROFILE) {
+ // We cannot guarantee that the request object will not be
recycled by the
+ // servlet runner, so use requestMarker instead.
+ requestMarker = new Profiler.RequestMarker (request);
+ profiler.startEvent (requestMarker, WHOLE_REQUEST);
+ }
+
if (LOG) logger.log(this, "Starting request", Logger.INFO);
// if verbose mode is on, take a time snapshot for later evaluation
@@ -243,10 +269,6 @@
// this may be needed if debug is turned on
ByteArrayOutputStream debugStream = null;
- // get the request flags
- boolean CACHE = getFlag(request, "cache", true);
- boolean DEBUG = getFlag(request, "debug", false);
-
// get the request user agent
String agent = request.getParameter("user-Agent");
if (agent == null) agent = request.getHeader("user-Agent");
@@ -264,11 +286,11 @@
}
Page page = null;
-
+
boolean lock = false;
-
+
String encodedRequest = Utils.encode( request );
-
+
try {
if ( CACHE ) {
// ask if the cache contains the page requested and if it's
@@ -278,10 +300,10 @@
// if the page isn't in cache block any furhter access to
this page
// until it get's put into cache
if ( page == null ) {
-
+
// lock this page while we build it and put it in cache
lock = this.blocker.lock( encodedRequest );
-
+
if ( ! lock ) {
// we were blocked so by another thread processing
this page
// so maybe it's in cache now
@@ -289,95 +311,98 @@
}
}
}
-
+
// the page was not found in the cache or the cache was
// disabled, we need to process it
-
-
+
+
if (page == null) {
-
- synchronized( this ) {
-
- if (LOG) logger.log(this, "Creating page",
Logger.DEBUG);
-
- // continue until the page is done.
- for (int i = 0; i < LOOPS; i++) {
- // catch if any OutOfMemoryError is thrown
- try {
- // create the Page wrapper
- page = new Page();
-
- // get the document producer
- Producer producer =
producers.getProducer(request);
-
- // set the producer as a page changeable point
- page.setChangeable(producer);
-
- // pass the produced stream to the parser
- Document document =
producer.getDocument(request);
-
- if (LOG) logger.log(this, "Document produced",
Logger.DEBUG);
-
- // pass needed parameters to the processor
pipeline
- Hashtable environment = new Hashtable();
- environment.put("path",
producer.getPath(request));
- environment.put("browser",
browsers.map(agent));
- environment.put("request", request);
- environment.put("response", response);
- if (servletContext != null)
environment.put("context", servletContext);
-
- // process the document through the document
processors
- while (true) {
- Processor processor =
processors.getProcessor(document);
- if (processor == null) break;
- document = processor.process(document,
environment);
- page.setChangeable(processor);
- if (LOG) logger.log(this, "Document
processed", Logger.DEBUG);
- }
-
- // get the right formatter for the page
- Formatter formatter =
formatters.getFormatter(document);
-
- // FIXME: I know it sucks to encapsulate a nice
stream into
- // a long String to push it into the cache. In
the future,
- // we'll find a smarter way to do it.
-
- // format the page
- StringWriter writer = new StringWriter();
- formatter.format(document, writer,
environment);
-
- if (LOG) logger.log(this, "Document formatted",
Logger.DEBUG);
-
- // fill the page bean with content
- page.setContent(writer.toString());
-
- // set content type together with encoding if
appropriate
- String encoding = formatter.getEncoding();
- if (encoding != null) {
- page.setContentType(formatter.getMIMEType()
+ "; charset=" + encoding);
- } else {
-
page.setContentType(formatter.getMIMEType());
- }
-
- // page is done without memory errors so exit
the loop
- break;
- } catch (OutOfMemoryError e) {
- if (LOG) logger.log(this, "Triggered
OutOfMemory", Logger.WARNING);
- // force the cache to free some of its content.
- cache.flush();
- // reset the page to signal the error
- page = null;
+
+ if (LOG) logger.log(this, "Creating page", Logger.DEBUG);
+
+ // continue until the page is done.
+ for (int i = 0; i < LOOPS; i++) {
+ // catch if any OutOfMemoryError is thrown
+ try {
+ // create the Page wrapper
+ page = new Page();
+
+ // get the document producer
+ Producer producer = producers.getProducer(request);
+
+ // set the producer as a page changeable point
+ page.setChangeable(producer);
+
+ // pass the produced stream to the parser
+ if (PROFILE) profiler.startEvent (requestMarker,
producer.getClass ());
+ Document document = producer.getDocument(request);
+ if (PROFILE) profiler.finishEvent (requestMarker,
producer.getClass ());
+
+ if (LOG) logger.log(this, "Document produced",
Logger.DEBUG);
+
+ // pass needed parameters to the processor pipeline
+ Hashtable environment = new Hashtable();
+ environment.put("path", producer.getPath(request));
+ environment.put("browser", browsers.map(agent));
+ environment.put("request", request);
+ environment.put("response", response);
+ if (servletContext != null)
environment.put("context", servletContext);
+
+ // process the document through the document
processors
+ while (true) {
+ Processor processor =
processors.getProcessor(document);
+ if (processor == null) break;
+ if (PROFILE) profiler.startEvent
(requestMarker, processor.getClass ());
document = processor.process(document, environment);
+ page.setChangeable(processor);
+ if (PROFILE) profiler.finishEvent
(requestMarker, processor.getClass ());
+ if (LOG) logger.log(this, "Document processed",
Logger.DEBUG);
}
+
+ // get the right formatter for the page
+ Formatter formatter =
formatters.getFormatter(document);
+
+ // FIXME: I know it sucks to encapsulate a nice
stream into
+ // a long String to push it into the cache. In the
future,
+ // we'll find a smarter way to do it.
+
+ // format the page
+ if (PROFILE) profiler.startEvent (requestMarker,
formatter.getClass ());
+ StringWriter writer = new StringWriter();
+ formatter.format(document, writer, environment);
+ if (PROFILE) profiler.finishEvent (requestMarker,
formatter.getClass ());
+
+ if (LOG) logger.log(this, "Document formatted",
Logger.DEBUG);
+
+ // fill the page bean with content
+ if (PROFILE) profiler.startEvent (requestMarker,
OUTPUTTING);
+ page.setContent(writer.toString());
+
+ // set content type together with encoding if
appropriate
+ String encoding = formatter.getEncoding();
+ if (encoding != null) {
+ page.setContentType(formatter.getMIMEType() +
"; charset=" + encoding);
+ } else {
+ page.setContentType(formatter.getMIMEType());
+ }
+
+ // page is done without memory errors so exit the
loop
+ break;
+ } catch (OutOfMemoryError e) {
+ if (LOG) logger.log(this, "Triggered OutOfMemory",
Logger.WARNING);
+ // force the cache to free some of its content.
+ cache.flush();
+ // reset the page to signal the error
+ page = null;
}
}
}
-
+
if (page == null) {
if (LOG) logger.log(this, "System is out of memory",
Logger.EMERGENCY);
throw new Exception("FATAL ERROR: the system ran out of
memory when"
+ " processing the request. Increase your JVM
memory.");
}
-
+
if (DEBUG) {
// send the debug message and restore the streams
Frontend.print(response, "Debugging " +
request.getRequestURI(), debugStream.toString());
@@ -386,13 +411,13 @@
} else {
// set the response content type
response.setContentType(page.getContentType());
-
+
// get the output writer
PrintWriter out = response.getWriter();
-
+
// send the page
out.println(page.getContent());
-
+
// if verbose mode is on the the output type allows it
// and the HTTP request isn't a HEAD
// print some processing info as a comment
@@ -404,16 +429,18 @@
+ Cocoon.version() + " -->");
//out.println("<!-- free memory: " +
Runtime.getRuntime().freeMemory() + " -->");
}
-
+
// send all content so that client doesn't wait while
caching.
out.flush();
+ profiler.finishEvent (requestMarker, OUTPUTTING);
}
-
+
if (LOG) logger.log(this, "response sent to client",
Logger.WARNING);
-
+ profiler.finishEvent (requestMarker, WHOLE_REQUEST);
+
// cache the created page.
cache.setPage(page, request);
-
+
} finally {
// if there is a lock make sure it is released,
// otherwise this page could never be served
@@ -421,7 +448,7 @@
this.blocker.unlock( encodedRequest );
}
}
-
+
}
/**
@@ -477,7 +504,7 @@
private Hashtable blocks = new Hashtable();
-
+
/**
* Checks if a key is being blocked, and if so blocks this request
until notified.
* If the key is not locked then it becomes locked, so any
subsequent calls will block.
@@ -485,55 +512,48 @@
* @param key - The object to be locked.
* @return boolean - ture = a lock was obtained, false = the caller
was blocked.
*/
- public boolean lock( Object key )
+ public synchronized boolean lock( Object key )
{
boolean locked = false;
-
+
if ( ! this.blocks.containsKey(key) ) {
// flag the key as locked
System.err.println( "Locking: " + key );
this.blocks.put( key, key );
locked = true;
-
+
} else {
// block the call
System.err.println( "Blocking: " + key );
try {
- // synchronization is required to be an owner of this
objects monitor
- synchronized( this ) {
- // wait until the block is released by the blocking
thread
- while( this.blocks.containsKey(key) ) {
- wait();
- }
+ // wait until the block is released by the blocking
thread
+ while( this.blocks.containsKey(key) ) {
+ wait();
}
} catch( InterruptedException ie ) {
System.err.println( "Wait for '" + key + "' was
interrupted" );
}
}
-
+
System.err.println( "Total locks for all pages: " +
this.blocks.size() );
return locked;
-
} // lock(Object)
-
-
+
+
/**
* @param key - The object who's lock is to be removed, all waiting
threads are notified.
*/
- public void unlock( Object key )
+ public synchronized void unlock( Object key )
{
// notify all waiting threads if there was a lock on this key
if ( this.blocks.remove(key) != null ) {
System.err.println( "Releasing lock on: " + key );
- // synchronization is required to be an owner of this
objects monitor
- synchronized( this ) {
- notifyAll();
- }
+ notifyAll();
}
} // unlock(Object)
-
+
} // inner class Block
} // class Engine
________________________________________________________________________
Get Your Private, Free E-mail from MSN Hotmail at http://www.hotmail.com
Re: [PATCH] [1.8] Optional profiler, and fixes for overzealous
synchronization
Posted by Stefano Mazzocchi <st...@apache.org>.
Robin Green wrote:
>
> Oops. With the attachment this time.
>
> Four patches in one here. More coming this weekend hopefully (but I always
> say that, and never deliver... :)
>
> 1. The cocoon 1.8-dev pipeline is now essentially single-threaded (per
> Engine, which means per servlet context). This was added with the blocking
> changes in the latest version of Engine.java, but it doesn't make sense. The
> new system of blocking per page should be quite adequate for efficiency - no
> need to hold up a whole site because of one slow page (perhaps a page which
> gets data from an external source) - and in fact blocking a whole site makes
> blocking individual pages totally redundant, so it doesn't make sense in
> that way either.
>
> 2. Synchronization on wait() and notify() isn't a pointless bureaucratic
> demand - it is explictly required because it requires a little bit of
> thought. Synchronization is meant to be wide enough to prevent missed
> notifications - and in the case of inner class Block a missed notification
> could occur, causing a hang on a request. Imagine that the lock method was
> called, and a context switch (i.e. switch to another thread) occured on the
> line
>
> System.err.println( "Blocking: " + key );
>
> whereupon another thread removed the key and called notifyAll(). In this
> scenario the first thread would miss the notification and would block
> forever. (Of course, the bug mentioned above means that this bug would never
> occur in the current release.)
>
> 3. The profiler class (in attached newfiles.zip) can be used to record the
> time taken by each class in the pipeline for any request. A very simple
> samples/profiler/profiler.xml and profile.xsl (in attached zip) can be used
> to view the results. The profiling is off by default, and can be enabled by
> uncommenting
>
> #profiler.enabled=true
>
> in the (updated) cocoon.properties file. Obviously, it needs Engine.java to
> be modified, as below, for it to be able to record.
>
> We have found it quite useful to see the length of time taken by each stage
> - it seems that a stylesheet with a linear-to-tabular conversion (i.e.
> splitting into blocks of 5) and with an xsl:import takes 2.5 seconds - as
> opposed to 0.5 seconds for a standard stylesheet - on our very slow test
> machine. Now to find out which of those is causing the difference!
>
> NOTE: Feel free to change the com.itao.xml packagename for DOMWriter.
>
> 4. Rationalisation of global and request options in Engine.java. A couple of
> people have requested to turn off the VERBOSE option without rebuilding
> Cocoon. Well now you can - and you can control it per request, as well.
These sounds all great patches.
I'm confident you'll get voted in so I'll simply wait for you to add
those patches yourself.
I told you I'm a lazy butt :)
--
Stefano Mazzocchi One must still have chaos in oneself to be
able to give birth to a dancing star.
<st...@apache.org> Friedrich Nietzsche
--------------------------------------------------------------------
Missed us in Orlando? Make it up with ApacheCON Europe in London!
------------------------- http://ApacheCon.Com ---------------------