cocoon-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Robin Green" <gree...@hotmail.com>
Subject [PATCH] [1.8] Optional profiler, and fixes for overzealous synchronization
Date Thu, 24 Aug 2000 19:08:44 GMT
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

Mime
View raw message