From a7495e05469a7efa4a144bd2b8fb90c00763fc67 Mon Sep 17 00:00:00 2001
From: hextraza <hextraza@fantasia.localdomain>
Date: Thu, 16 Feb 2023 10:55:53 -0800
Subject: [PATCH] Add more timing log information

---
 src/parse/bam.rs               | 12 ++++++++++++
 src/parse/sorted_bam_reader.rs |  1 +
 2 files changed, 13 insertions(+)

diff --git a/src/parse/bam.rs b/src/parse/bam.rs
index 7d5bdbc..c8ed6ba 100644
--- a/src/parse/bam.rs
+++ b/src/parse/bam.rs
@@ -2,6 +2,8 @@ use super::sorted_bam_reader::SortedBamReader;
 use debruijn::dna_string::DnaString;
 use rust_htslib::bam::record::Aux;
 
+use std::time::{Duration, Instant};
+
 const READ_BLOCK_REPORT_SIZE: usize = 1000000;
 const MAX_RECORD_ERROR_REPORT_SIZE: usize = 100;
 
@@ -67,12 +69,16 @@ impl UMIReader {
         self.next_iteration_key.clear();
 
         loop {
+            let start = Instant::now();
             let r = self.reader.next();
+            let duration = start.elapsed();
+            //println!("time to load read read/sort UMI from disk: {:?}", duration);
 
             if r.is_err() {
                 return None;
             }
 
+            let start = Instant::now();
             self.read_counter = self.read_counter + 1;
 
             if self.read_counter % READ_BLOCK_REPORT_SIZE == 0 && self.read_counter != 0 {
@@ -160,6 +166,9 @@ impl UMIReader {
                 self.current_cell_barcode = current_cell_barcode.clone();
 
                 self.current_iteration_key = current_iteration_key;
+
+                let duration = start.elapsed();
+                //println!("time to push read to readlist: {:?}", duration);
             } else {
                 self.next_umi_group.push(seq);
                 self.next_metadata_group
@@ -167,6 +176,9 @@ impl UMIReader {
                 self.next_umi = read_umi.clone();
                 self.next_cell_barcode = current_cell_barcode;
                 self.next_iteration_key = current_iteration_key;
+
+                let duration = start.elapsed();
+                //println!("time to push read to NEXT readlist: {:?}", duration);
                 return Some(true);
             }
         }
diff --git a/src/parse/sorted_bam_reader.rs b/src/parse/sorted_bam_reader.rs
index cf62426..40de92d 100644
--- a/src/parse/sorted_bam_reader.rs
+++ b/src/parse/sorted_bam_reader.rs
@@ -20,6 +20,7 @@ impl SortedBamReader {
     }
 
     fn fill_buffer(&mut self) {
+        println!("filling buffer and sorting");
         self.dna_sorted_buffer.clear();
         self.dna_sorted_buffer.append(&mut self.next_records);
         self.current_umi = self.next_umi.clone();