Fix for inaccurate and misleading timing information, now only prints estimated time to completion when the location flag isn't set

git-svn-id: file:///humgen/gsa-scr1/gsa-engineering/svn_contents/trunk@25 348d0f76-0448-11de-a6fe-93d51630548a

java/src/edu/mit/broad/sting/atk/TraversalEngine.java

@@ -31,6 +31,8 @@ public class TraversalEngine {
     private ValidationStringency strictness = ValidationStringency.STRICT;
 
     private long startTime = -1;
+    private long lastProgressPrintTime = -1;
+    private long MAX_PROGRESS_PRINT_TIME = 5 * 1000; // 10 seconds in millisecs
     private long maxReads = -1;
     private long nRecords = 0;
     private SAMFileReader samReader = null;
@@ -63,7 +65,7 @@ public class TraversalEngine {
     }
 
     protected int initialize() {
-        startTime = System.currentTimeMillis();
+        lastProgressPrintTime = startTime = System.currentTimeMillis();
         loadReference();
         //testReference();
         //loadReference();
@@ -146,19 +148,34 @@ public class TraversalEngine {
     // functions for dealing with the reference sequence
     //
     // --------------------------------------------------------------------------------------------------------------
+    /**
+     *
+     * @param curTime (current runtime, in millisecs)
+     * @return true if the maximum interval (in millisecs) has passed since the last printing
+     */
+
+    private boolean maxElapsedIntervalForPrinting(final long curTime) {
+        return (curTime - this.lastProgressPrintTime) > MAX_PROGRESS_PRINT_TIME;
+    }
+
     public void printProgress(final String type, GenomeLoc loc) { printProgress( false, type, loc ); }
 
     public void printProgress( boolean mustPrint, final String type, GenomeLoc loc ) {
         final long nRecords = this.nRecords;
-
+        final long curTime = System.currentTimeMillis();
-        if ( mustPrint || nRecords % 100000 == 0 ) {
+        final double elapsed = (curTime - startTime) / 1000.0;
-            final double elapsed = (System.currentTimeMillis() - startTime) / 1000.0;
+        //System.out.printf("Cur = %d, last print = %d%n", curTime, lastProgressPrintTime);
+                    
+        if ( mustPrint || nRecords % 100000 == 0 || maxElapsedIntervalForPrinting(curTime)) {
+            this.lastProgressPrintTime = curTime;
             final double secsPer1MReads = (elapsed * 1000000.0) / nRecords;
             if ( loc != null )
-                System.out.printf("Traversed to %s, processing %d %s %.2f secs (%.2f secs per 1M %s)%n", loc, nRecords, type, elapsed, secsPer1MReads, type);
+                System.out.printf("[PROGRESS] Traversed to %s, processing %d %s %.2f secs (%.2f secs per 1M %s)%n", loc, nRecords, type, elapsed, secsPer1MReads, type);
             else
-                System.out.printf("Traversed %d %s %.2f secs (%.2f secs per 1M %s)%n", nRecords, type, elapsed, secsPer1MReads, type);
+                System.out.printf("[PROGRESS] Traversed %d %s %.2f secs (%.2f secs per 1M %s)%n", nRecords, type, elapsed, secsPer1MReads, type);
-            System.out.printf("  -> %s%n", samReadingTracker.progressMeter());
+
+            if ( this.locs == null )
+                System.out.printf("[PROGRESS]   -> %s%n", samReadingTracker.progressMeter());
         }
     }
 

java/src/edu/mit/broad/sting/utils/FileProgressTracker.java

@@ -144,8 +144,8 @@ public class FileProgressTracker<T> implements Iterator<T> {
         //printStatus();
         return String.format("Est. %.2f%% completed, time remaining (%.2f hrs / %.2f min) of (%.2f hrs / %.2f min) total",
                 estFractionProgressThroughFile() * 100.0,
-                estTimeTotal() / (60*60), estTimeTotal() / (60),
+                estTimeRemaining() / (60*60), estTimeRemaining() / 60,
-                estTimeRemaining() / (60*60), estTimeRemaining() / 60);
+                estTimeTotal() / (60*60), estTimeTotal() / (60));                
     }
 
     public ArrayList<Long> recordSizes() {

scripts/buildRODs.sh

@@ -0,0 +1,2 @@
+java -Xmx40000m -cp out/production/AnalysisTK:trunk/java/jars/functionalj.jar edu.mit.broad.sting.atk.PrepareROD REF_FILE_ARG=/seq/references/Homo_sapiens_assembly18/v0/Homo_sapiens_assembly18.fasta ROD_FILE=/seq/references/dbsnp/downloads/snp129_hg18.txt OUT=`echo $1/snp129_hg18.txt.rod` ROD_TYPE=dbSNP ROD_NAME=dbSNP
+