[gate-cvs] SF.net SVN: gate:[18169] gcp/trunk/src/gate/cloud/batch/BatchRunner.java

[<joh...@us...>]

Revision: 18169
          http://sourceforge.net/p/gate/code/18169
Author:   johann_p
Date:     2014-07-09 14:48:59 +0000 (Wed, 09 Jul 2014)
Log Message:
-----------
Add some more information about elapsed times and memory sizes to the log.

Modified Paths:
--------------
    gcp/trunk/src/gate/cloud/batch/BatchRunner.java

Modified: gcp/trunk/src/gate/cloud/batch/BatchRunner.java
===================================================================
--- gcp/trunk/src/gate/cloud/batch/BatchRunner.java	2014-07-09 01:19:40 UTC (rev 18168)
+++ gcp/trunk/src/gate/cloud/batch/BatchRunner.java	2014-07-09 14:48:59 UTC (rev 18169)
@@ -145,7 +145,15 @@
       resultQueue = new LinkedBlockingQueue<ProcessResult>();
       if(totalDocs > 0) {
         // create the document Processor
+        // This will also fill the pool with the custom-duplicated copies,
+        // so we can find the time needed for this after creating the object
         processor = new PooledDocumentProcessor(executor.getCorePoolSize());
+        // TODO
+        log.info("Duplication finished");
+        log.info("Total allocated memory: "+(runtime.totalMemory()/MB)+"M");
+        log.info("Used memory: "+((runtime.totalMemory()-runtime.freeMemory())/MB)+"M");
+        duplicationFinishedTime = System.currentTimeMillis();
+        log.info("Duplication time (seconds): "+(duplicationFinishedTime-loadingFinishedTime)/1000.0);
         processor.setController(batch.getGateApplication());
         processor.setExecutor(executor);
         processor.setInputHandler(batch.getInputHandler());
@@ -408,7 +416,13 @@
       }
     }
     long processingFinishedTime = System.currentTimeMillis();
-    log.info("Processing time (seconds): "+(processingFinishedTime-loadingFinishedTime)/1000.0);
+    log.info("Processing finished");
+    log.info("Total allocated memory: "+(runtime.totalMemory()/MB)+"M");
+    log.info("Used memory: "+((runtime.totalMemory()-runtime.freeMemory())/MB)+"M");
+    // if we did not need to process anything then the duplicationFinishedTime will not have
+    // been set and be 0. In that case, set it to the loadingFinishedTime
+    if(duplicationFinishedTime==0) duplicationFinishedTime = loadingFinishedTime;
+    log.info("Processing time (seconds): "+(processingFinishedTime-duplicationFinishedTime)/1000.0);
     log.info("Total time (seconds): "+(processingFinishedTime-startTime)/1000.0);
     
   }
@@ -513,7 +527,10 @@
 
   static long startTime = System.currentTimeMillis();
   static long loadingFinishedTime;
-  
+  static long duplicationFinishedTime;
+  static Runtime runtime = Runtime.getRuntime();
+  static final int MB = 1024*1024;
+
   /**
    * Main entry point.  This can be invoked in one of two ways: the "legacy" 
    * mode which expects two parameters and a command line mode which allows
@@ -650,8 +667,6 @@
       }
     });
 
-    final int MB = 1024*1024;
-    Runtime runtime = Runtime.getRuntime();
     log.info("Initial total allocated memory: "+(runtime.totalMemory()/MB)+"M");
     log.info("Initial used memory: "+((runtime.totalMemory()-runtime.freeMemory())/MB)+"M");
 
@@ -784,8 +799,9 @@
           log.info("Number of documents found: "+docIds.size());
           aBatch.setDocumentIDs(docIds.toArray(new DocumentID[docIds.size()]));
           aBatch.init();
-        }
+        }    
       }
+      log.info("Loading finished");
       log.info("Total allocated memory: "+(runtime.totalMemory()/MB)+"M");
       log.info("Used memory: "+((runtime.totalMemory()-runtime.freeMemory())/MB)+"M");
       loadingFinishedTime = System.currentTimeMillis();

This was sent by the SourceForge.net collaborative development platform, the world's largest Open Source development site.