diff --git a/src/main/java/htsjdk/samtools/util/AbstractProgressLogger.java b/src/main/java/htsjdk/samtools/util/AbstractProgressLogger.java index 0b7dd7275f..f88d8fa026 100644 --- a/src/main/java/htsjdk/samtools/util/AbstractProgressLogger.java +++ b/src/main/java/htsjdk/samtools/util/AbstractProgressLogger.java @@ -18,10 +18,14 @@ abstract public class AbstractProgressLogger implements ProgressLoggerInterface private long startTime; private final NumberFormat fmt = new DecimalFormat("#,###"); private final NumberFormat timeFmt = new DecimalFormat("00"); - private long processed; - private long lastStartTime; - private String lastChrom; - private int lastPos; + private long processed = 0; + // Set to -1 until the first record is added + private long lastStartTime = -1; + private String lastChrom = null; + private int lastPos = 0; + private String lastReadName = null; + private long countNonIncreasing = 0; + final static private long PRINT_READ_NAME_THRESHOLD = 1000; /** * Construct an AbstractProgressLogger. @@ -60,10 +64,18 @@ private synchronized void record() { if (this.lastChrom == null) readInfo = "*/*"; else readInfo = this.lastChrom + ":" + fmt.format(this.lastPos); + final String rnInfo; + + if (lastReadName != null && countNonIncreasing > PRINT_READ_NAME_THRESHOLD) { + rnInfo = ". Last read name: " + lastReadName; + } else { + rnInfo = ""; + } + final long n = (this.processed % this.n == 0) ? this.n : this.processed % this.n; log(this.verb, " ", processed, " " + noun + ". Elapsed time: ", elapsed, "s. Time for last ", fmt.format(n), - ": ", period, "s. Last read position: ", readInfo); + ": ", period, "s. Last read position: ", readInfo, rnInfo); } /** @@ -71,7 +83,7 @@ private synchronized void record() { * @return boolean true if logging was triggered, false otherwise */ public synchronized boolean log() { - if (this.processed % this.n != 0) { + if (processed % this.n != 0) { record(); return true; } @@ -80,22 +92,33 @@ public synchronized boolean log() { } } - @Override - public synchronized boolean record(final String chrom, final int pos) { - this.lastChrom = chrom; - this.lastPos = pos; - if (this.lastStartTime == -1) { - this.lastStartTime = System.currentTimeMillis(); + protected synchronized boolean record(final String chrom, final int pos, final String rname) { + if (chrom != null && chrom.equals(lastChrom) && pos < lastPos) { + countNonIncreasing++; + if (countNonIncreasing == PRINT_READ_NAME_THRESHOLD) { + log("Seen many non-increasing record positions. Printing Read-names as well."); + } + } else { + lastChrom = chrom; + } + lastPos = pos; + lastReadName = rname; + if (lastStartTime == -1) { + lastStartTime = System.currentTimeMillis(); } - if (++this.processed % this.n == 0) { + if (++processed % n == 0) { record(); return true; - } - else { + } else { return false; } } + @Override + public synchronized boolean record(final String chrom, final int pos) { + return record(chrom, pos, null); + } + /** * Records that a given record has been processed and triggers logging if necessary. * @return boolean true if logging was triggered, false otherwise @@ -103,10 +126,9 @@ public synchronized boolean record(final String chrom, final int pos) { @Override public synchronized boolean record(final SAMRecord rec) { if (SAMRecord.NO_ALIGNMENT_REFERENCE_NAME.equals(rec.getReferenceName())) { - return record(null, 0); - } - else { - return record(rec.getReferenceName(), rec.getAlignmentStart()); + return record(null, 0, rec.getReadName()); + } else { + return record(rec.getReferenceName(), rec.getAlignmentStart(), rec.getReadName()); } } @@ -114,7 +136,9 @@ public synchronized boolean record(final SAMRecord rec) { @Override public boolean record(final SAMRecord... recs) { boolean triggered = false; - for (final SAMRecord rec : recs) triggered = record(rec) || triggered; + for (final SAMRecord rec : recs) { + triggered = record(rec) || triggered; + } return triggered; } @@ -125,22 +149,25 @@ public boolean record(final SAMRecord... recs) { public long getElapsedSeconds() { return (System.currentTimeMillis() - this.startTime) / 1000; } /** Resets the start time to now and the number of records to zero. */ - public void reset() { + public synchronized void reset() { startTime = System.currentTimeMillis(); processed = 0; // Set to -1 until the first record is added lastStartTime = -1; lastChrom = null; lastPos = 0; + lastReadName = null; + countNonIncreasing = 0; } /** Left pads a string until it is at least the given length. */ - private String pad (String in, final int length) { - while (in.length() < length) { - in = " " + in; + static String pad(final String in, final int length) { + final StringBuilder inBuilder = new StringBuilder(Math.max(length, in.length())); + while (inBuilder.length() < length - in.length()) { + inBuilder.append(" "); } - return in; + return inBuilder.append(in).toString(); } /** Formats a number of seconds into hours:minutes:seconds. */ diff --git a/src/main/java/htsjdk/samtools/util/Log.java b/src/main/java/htsjdk/samtools/util/Log.java index dfe758a39c..ec99bbb60b 100644 --- a/src/main/java/htsjdk/samtools/util/Log.java +++ b/src/main/java/htsjdk/samtools/util/Log.java @@ -117,7 +117,7 @@ public static final boolean isEnabled(final LogLevel level) { */ private void emit(final LogLevel level, final Throwable throwable, final Object... parts) { if (isEnabled(level)) { - StringBuffer tmp = new StringBuffer(); + final StringBuffer tmp = new StringBuffer(); tmp.append(level.name()) .append('\t') .append(getTimestamp()) @@ -145,10 +145,10 @@ private void emit(final LogLevel level, final Throwable throwable, final Object. // Print out the exception if there is one if (throwable != null) { - synchronized (this.out) { + synchronized (this.out) { this.out.println(tmp.toString()); throwable.printStackTrace(this.out); - } + } } else { this.out.println(tmp.toString()); diff --git a/src/test/java/htsjdk/samtools/BAMFileWriterTest.java b/src/test/java/htsjdk/samtools/BAMFileWriterTest.java index 790244ffac..b021b3fa11 100644 --- a/src/test/java/htsjdk/samtools/BAMFileWriterTest.java +++ b/src/test/java/htsjdk/samtools/BAMFileWriterTest.java @@ -78,10 +78,9 @@ private void testHelper(final SAMRecordSetBuilder samRecordSetBuilder, final SAM } final File tempMetrics = File.createTempFile("CGTagTest", ".validation_metrics"); - try ( - final SamReader samReader = SamReaderFactory.makeDefault().open(bamFile); - final OutputStream outputStream = new FileOutputStream(tempMetrics); - final PrintWriter printWriter = new PrintWriter(outputStream)) { + try (final SamReader samReader = SamReaderFactory.makeDefault().open(bamFile); + final OutputStream outputStream = new FileOutputStream(tempMetrics); + final PrintWriter printWriter = new PrintWriter(outputStream)) { new SamFileValidator(printWriter, 100).validateSamFileSummary(samReader, null); } diff --git a/src/test/scala/htsjdk/samtools/fastq/FastqReaderWriterTest.scala b/src/test/scala/htsjdk/samtools/fastq/FastqReaderWriterTest.scala index e85c2310d7..f2b64f4186 100644 --- a/src/test/scala/htsjdk/samtools/fastq/FastqReaderWriterTest.scala +++ b/src/test/scala/htsjdk/samtools/fastq/FastqReaderWriterTest.scala @@ -176,5 +176,4 @@ class FastqReaderWriterTest extends UnitSpec { an[Exception] shouldBe thrownBy { new FastqReader(noSeqHeader).iterator().toSeq } an[Exception] shouldBe thrownBy { new FastqReader(noQualHeader).iterator().toSeq } } - } diff --git a/src/test/scala/htsjdk/samtools/util/AbstractProgressLoggerTest.scala b/src/test/scala/htsjdk/samtools/util/AbstractProgressLoggerTest.scala new file mode 100644 index 0000000000..eb3b5c8652 --- /dev/null +++ b/src/test/scala/htsjdk/samtools/util/AbstractProgressLoggerTest.scala @@ -0,0 +1,17 @@ +package htsjdk.samtools.util + +import htsjdk.UnitSpec + +class AbstractProgressLoggerTest extends UnitSpec { + + "AbstractProgressLoggerTest.pad" should "pad the right amount of spaces in " in { + Seq( + ("hello", 10, " hello"), + ("hello", 6, " hello"), + ("hello", 5, "hello"), + ("hello", 4, "hello"), + ("hello", -1, "hello")).foreach { case (in, len, expected) => + AbstractProgressLogger.pad(in, len) shouldEqual expected + } + } +}