Changeset 26240 for gs2-extensions

Timestamp:

2012-09-25T12:40:56+12:00 (12 years ago)

Author:

jmt12

Message:

Modifications to progress messages to improve extracting information from the logs in an automated fashion

File:

• gs2-extensions/parallel-building/trunk/src/opt/Terrier/FileIndexer.java (modified) (24 diffs)

gs2-extensions/parallel-building/trunk/src/opt/Terrier/FileIndexer.java

@@ -20 +20 @@
 import java.util.Iterator;
 
+import org.apache.log4j.Level;
 import org.apache.log4j.Logger;
 
@@ -81 +82 @@
   public FileIndexer(String index_prefix)
   {
-    logger.info("FileIndexer::FileIndexer(" + index_prefix + ")");
+    ///ogger.info("FileIndexer::FileIndexer(" + index_prefix + ")");
     this.index_prefix = index_prefix;
     this.supported_extensions = new HashSet<String>();
@@ -134 +135 @@
   public boolean canIndex(String file_path)
   {
-    logger.info("FileIndexer::canIndex(" + file_path.toString() + ")");
     // we may have specified a default Document class for all files encountered
     if (!ApplicationSetup.getProperty("indexing.simplefilecollection.defaultparser","").equals(""))
@@ -145 +145 @@
     String file_extension = file_path.substring(file_path.lastIndexOf(".") + 1);
     // - see if it exists in the array of supported extensions
-    return this.supported_extensions.contains(file_extension);
+    boolean result = this.supported_extensions.contains(file_extension);
+    logger.info("[P1] Can index \"" + file_path.toString() + "\"? => " + result);
+    return result;
   }
   /** canIndex(String) **/
@@ -153 +155 @@
   public void close()
   {
-    logger.info("FileIndexer::close()");
+    ///ogger.info("FileIndexer::close()");
     this.file_list.clear();
     this.file_list = null;
@@ -163 +165 @@
   /** @function deleteIndex
    */
-  public void deleteIndex(String prefix)
-  {
-    logger.info("FileIndexer::deleteIndex(" + prefix + ")");
+  public void deleteIndex(String prefix, String logging_name)
+  {
+    logger.info("[" + logging_name + "] Delete index " + prefix);
     // and that all old files for this index are removed
     File index_path = new File(ApplicationSetup.TERRIER_INDEX_PATH);
@@ -178 +180 @@
     }
   }
-  /** deleteIndex(String) **/
+  /** deleteIndex(String, String) **/
+
+  /** @function epochTime
+   *  Returns the current time in seconds since 1970JAN01
+   */
+  public long epochTime()
+  {
+    return System.currentTimeMillis()/1000;
+  }
+  /** epochTime() **/
 
   /** @function listIndexes
@@ -184 +195 @@
   public ArrayDeque<String> listIndexes(boolean include_default)
   {
-    logger.info("FileIndexer::listIndexes(" + include_default + ")");
+    ///ogger.info("FileIndexer::listIndexes(" + include_default + ")");
     File index_path = new File(ApplicationSetup.TERRIER_INDEX_PATH);
     String default_index_prefix = ApplicationSetup.getProperty("terrier.index.prefix", "data");
@@ -191 +202 @@
     HashSet<String> index_parts_set = new HashSet<String>();
     File files[] = index_path.listFiles();
-    for (int i = 0; i < files.length; i++)
-    {
-      String file_name = files[i].getName();
-      if (include_default || !file_name.startsWith(default_index_prefix))
-      {
-        String prefix = file_name.substring(0, file_name.indexOf("."));
-        index_parts_set.add(prefix);
-      }
+    if (files != null)
+    {
+      for (int i = 0; i < files.length; i++)
+      {
+        String file_name = files[i].getName();
+        if (include_default || !file_name.startsWith(default_index_prefix))
+        {
+          String prefix = file_name.substring(0, file_name.indexOf("."));
+          index_parts_set.add(prefix);
+        }
+      }
+    }
+    else
+    {
+      logger.error("[P3] Error! No indexes found - did indexing fail?");
     }
     // we then turn the hashset into a nice list (in this case a deque)
@@ -213 +231 @@
   /**
    */
-  public void loadManifest(Path manifest_path)
-  {
-    logger.info("FileIndexer::loadManifest(" + manifest_path.toString() + ")");
+  public void loadManifest(String index_prefix, Path manifest_path)
+  {
+    logger.info("[B" + index_prefix + "] Load manifest " + manifest_path.toString());
     try
     {
@@ -238 +256 @@
   public boolean mergeIndexes(String prefix_one, String prefix_two)
   {
-    logger.info("FileIndexer::mergeIndexes(" + prefix_one + ", " + prefix_two + ")");
+    ///ogger.info("FileIndexer::mergeIndexes(" + prefix_one + ", " + prefix_two + ")");
     String prefix_default = ApplicationSetup.getProperty("terrier.index.prefix", "data");
     return this.mergeIndexes(prefix_one, prefix_two, prefix_default);
@@ -248 +266 @@
   public boolean mergeIndexes(String prefix_one, String prefix_two, String prefix_out)
   {
-    logger.info("FileIndexer::mergeIndexes(" + prefix_one + ", " + prefix_two + ", " + prefix_out + ")");
+    logger.info("[P3] Merge indexes " + prefix_one + " and " + prefix_two + " => " + prefix_out);
     // init
     String index_path = ApplicationSetup.TERRIER_INDEX_PATH;
@@ -257 +275 @@
     Index index_out = Index.createNewIndex(index_path, prefix_out);
     StructureMerger structure_merger = new StructureMerger(index_one, index_two, index_out);
+
+    // quiet logger
+    Logger root_logger = Logger.getRootLogger();
+    Level log_level = root_logger.getLevel();
+    root_logger.setLevel((Level) Level.OFF);
     structure_merger.mergeStructures();
     structure_merger = null;
-    CollectionStatistics collection_statistics = index_out.getCollectionStatistics();
-    logger.info("Number of Documents: " + collection_statistics.getNumberOfDocuments());
-    logger.info("Number of Tokens: " + collection_statistics.getNumberOfTokens());
-    logger.info("Number of Unique Terms: " + collection_statistics.getNumberOfUniqueTerms());
-    logger.info("Number of Pointers: " + collection_statistics.getNumberOfPointers());
-    collection_statistics = null;
+    root_logger.setLevel(log_level);
+
+    // Only print out statistics for 'data'
+    if (prefix_out.equals("data"))
+    {
+      CollectionStatistics collection_statistics = index_out.getCollectionStatistics();
+      logger.info("[P3] Number of Documents: " + collection_statistics.getNumberOfDocuments());
+      logger.info("[P3] Number of Tokens: " + collection_statistics.getNumberOfTokens());
+      logger.info("[P3] Number of Unique Terms: " + collection_statistics.getNumberOfUniqueTerms());
+      logger.info("[P3] Number of Pointers: " + collection_statistics.getNumberOfPointers());
+      collection_statistics = null;
+    }
+
+    // Cleanup and closedown
     try
     {
@@ -279 +310 @@
     index_two = null;
     index_out = null;
-    this.deleteIndex(prefix_one);
-    this.deleteIndex(prefix_two);
+    this.deleteIndex(prefix_one, "P3");
+    this.deleteIndex(prefix_two, "P3");
     prefix_one = null;
     prefix_two = null;
@@ -291 +322 @@
   public void renameIndex(String prefix_in)
   {
-    logger.info("FileIndexer::renameIndex(" + prefix_in + ")");
+    ///ogger.info("FileIndexer::renameIndex(" + prefix_in + ")");
     String default_prefix = ApplicationSetup.getProperty("terrier.index.prefix", "data");
     this.renameIndex(prefix_in, default_prefix);
@@ -301 +332 @@
   public void renameIndex(String prefix_in, String prefix_out)
   {
-    logger.info("FileIndexer::renameIndex(" + prefix_in + ", " + prefix_out + ")");
+    logger.info("[P3] Rename index " + prefix_in + " => " + prefix_out);
     prefix_in = prefix_in + ".";
     File index_path = new File(ApplicationSetup.TERRIER_INDEX_PATH);
@@ -334 +365 @@
   /** @function runIndex
    */
-  public void runIndex()
-  {
-    logger.info("FileIndexer::runIndex()");
+  public void runIndex(String batch_number)
+  {
+    logger.info("[B" + batch_number + "] create index");
     if (this.file_list == null || this.file_list.size() == 0)
     {
@@ -353 +384 @@
         return;
       }
-      this.deleteIndex(this.index_prefix);
+      this.deleteIndex(this.index_prefix, "F");
       // create the appropriate indexer
       Indexer indexer;
@@ -470 +501 @@
     FileIndexer file_indexer = new FileIndexer(index_prefix);
 
+    long epoch_time;
+
     switch(index_mode)
     {
     case PREPARE:
+      logger.info("[P1:" + file_indexer.epochTime() + "] Starting manifest preparation");
       // 3a. If we are in preparation mode, this is where we go through the
       //     files in the search path, adding those that are indexable by
@@ -567 +601 @@
       search_paths.clear();
       search_paths = null;
+      logger.info("[P1:" + file_indexer.epochTime() + "] Complete");
       break;
 
     case INDEX:
       // 3b. Load the manifest specified by the search path and index files
-      System.out.println("Mode: Index");
-      System.out.println("Manifest Path: " + a_path.toString());
-      System.out.println("Prefix: " + index_prefix);
+      String manifest_path = a_path.toString();
+      System.out.println("Mode:     Index");
+      System.out.println("Prefix:   " + index_prefix);
+      System.out.println("Manifest: " + manifest_path);
       System.out.println("Indexing: " + ApplicationSetup.getProperty("indexer.meta.forward.keys", "docno,filename"));
       System.out.println(divider);
-      file_indexer.loadManifest(a_path);
-      file_indexer.runIndex();
+
+      logger.info("[B" + index_prefix + ":" + file_indexer.epochTime() + "] Starting");
+      file_indexer.loadManifest(index_prefix, a_path);
+      file_indexer.runIndex(index_prefix);
+      logger.info("[B" + index_prefix + ":" + file_indexer.epochTime() + "] Complete");
       break;
 
     case MERGE:
+      logger.info("[P3:" + file_indexer.epochTime() + "] Starting index merging");
       System.out.println("Mode: Merge");
       System.out.println(divider);
       // 3c. User has requested a merging process.
-      logger.info("[" + (System.currentTimeMillis()/1000) + "] Merging started");
       // Look in the default index path and locate all of the indexes to merge
       // (all those not prefixed 'data')
@@ -597 +636 @@
         String index_part_two_prefix = index_parts.remove();
         String intermediate_index_prefix = "temp" + String.format("%03d", intermediate_file_counter);
-        logger.info("Merging index parts \"" + index_part_one_prefix + "\" and \"" + index_part_two_prefix + "\" into index \"" + intermediate_index_prefix + "\"");
+        ///ogger.info("Merging index parts \"" + index_part_one_prefix + "\" and \"" + index_part_two_prefix + "\" into index \"" + intermediate_index_prefix + "\"");
         file_indexer.mergeIndexes(index_part_one_prefix, index_part_two_prefix, intermediate_index_prefix);
         index_part_one_prefix = null;
@@ -611 +650 @@
         String index_part_one_prefix = index_parts.remove();
         String index_part_two_prefix = index_parts.remove();
-        logger.info("Merging index parts \"" + index_part_one_prefix + "\" and \"" + index_part_two_prefix + "\" into final index");
+        ///ogger.info("Merging index parts \"" + index_part_one_prefix + "\" and \"" + index_part_two_prefix + "\" into final index");
         file_indexer.mergeIndexes(index_part_one_prefix, index_part_two_prefix);
         index_part_one_prefix = null;
@@ -621 +660 @@
       {
         String index_part_prefix = index_parts.remove();
-        logger.info("Renaming index \"" + index_part_prefix + "\" into final index");
+        ///ogger.info("Renaming index \"" + index_part_prefix + "\" into final index");
         file_indexer.renameIndex(index_part_prefix);
         index_part_prefix = null;
@@ -628 +667 @@
       else
       {
-        logger.warn("No index parts detected - merge has no effect");
+        logger.warn("[P3] Warning! No index parts detected - merge has no effect");
       }
       // clean up
       index_parts.clear();
       index_parts = null;
-      logger.info("[" + (System.currentTimeMillis()/1000) + "] The merging is complete!");
+      logger.info("[P3:" + file_indexer.epochTime() + "] Complete");
       break;