diff --git a/Cargo.lock b/Cargo.lock index 3c0fcfdee..a537f55ef 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -406,7 +406,6 @@ dependencies = [ "io_utils", "itertools", "pager", - "perf_stats", "petgraph", "qd", "rayon", @@ -454,7 +453,6 @@ dependencies = [ "io_utils", "itertools", "lazy_static", - "perf_stats", "qd", "rayon", "regex", @@ -1248,15 +1246,6 @@ version = "2.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "d4fd5641d01c8f18a23da7b6fe29298ff4b55afcccdf78973b24cf3175fee32e" -[[package]] -name = "perf_stats" -version = "0.1.8" -dependencies = [ - "io_utils", - "libc", - "string_utils", -] - [[package]] name = "permutation" version = "0.4.1" @@ -1940,7 +1929,6 @@ dependencies = [ "fasta_tools", "flate2", "io_utils", - "perf_stats", "sha2", "string_utils", "vdj_ann", diff --git a/Cargo.toml b/Cargo.toml index ad02ea8bf..fb227c7b3 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -23,7 +23,6 @@ members = [ "io_utils", "kmer_lookup", "load_feature_bc", - "perf_stats", "stats_utils", "stirling_numbers", "string_utils", diff --git a/enclone/Cargo.toml b/enclone/Cargo.toml index d0f152657..6764478dd 100644 --- a/enclone/Cargo.toml +++ b/enclone/Cargo.toml @@ -30,7 +30,6 @@ equiv = { path = "../equiv" } graph_simple = { path = "../graph_simple" } io_utils = { path = "../io_utils" } itertools.workspace = true -perf_stats = { path = "../perf_stats" } petgraph = "0.6" qd = { git = "https://github.com/Barandis/qd" } rayon = "1" diff --git a/enclone/src/UNDOC_OPTIONS b/enclone/src/UNDOC_OPTIONS index 9ed7dba7a..4f7e4909d 100644 --- a/enclone/src/UNDOC_OPTIONS +++ b/enclone/src/UNDOC_OPTIONS @@ -275,8 +275,6 @@ HAPS_DEBUG: turn on debug mode for the HAPS option ROW_FILL_VERBOSE: special option for debugging -COMPE: COMP, plus enforce no unaccounted time (except up to 0.02 seconds) -UNACCOUNTED: show unaccounted time at each step EVIL_EYE: print logging to facilitate diagnosis of mysterious hanging TOOLTIP: add tooltip text to honeycomb plots diff --git a/enclone/src/allele.rs b/enclone/src/allele.rs index b8df12491..77982c06c 100644 --- a/enclone/src/allele.rs +++ b/enclone/src/allele.rs @@ -595,5 +595,4 @@ pub fn sub_alts( } } } - ctl.perf_stats(&t, "substituting alt alleles"); } diff --git a/enclone/src/enclone.test.tcr b/enclone/src/enclone.test.tcr index 09f62caa8..bb49e4aa4 100755 --- a/enclone/src/enclone.test.tcr +++ b/enclone/src/enclone.test.tcr @@ -5,5 +5,5 @@ set rootdir = `dirname $0` enclone \ TCR=`cat $rootdir/../../enclone_core/src/enclone.testdata.tcr | tail -n +3 | grep -v '#' | \ tr -d ' ' | head --bytes=-1 | tr '\n' ';' | tr -s ';'` \ - ANN COMP SHOW_BC MIN_DONORS=2 PLAIN NSILENT PRINT_FAILED_JOINS \ + ANN SHOW_BC MIN_DONORS=2 PLAIN NSILENT PRINT_FAILED_JOINS \ PRE=/mnt/assembly/vdj/current15 $* diff --git a/enclone/src/enclone.test2 b/enclone/src/enclone.test2 index 02d8ff20f..005f55695 100755 --- a/enclone/src/enclone.test2 +++ b/enclone/src/enclone.test2 @@ -5,5 +5,5 @@ set rootdir = `dirname $0` enclone \ BCR=`cat $rootdir/../../enclone_core/src/testdata.public.bcr.human | grep -v '#' | tr -d ' ' | grep -v '^$' | head --bytes=-1 | \ tr '\n' ';' | tr -s ';'` \ - ANN COMP SHOW_BC MIN_DONORS=2 PLAIN NSILENT PRINT_FAILED_JOINS \ + ANN SHOW_BC MIN_DONORS=2 PLAIN NSILENT PRINT_FAILED_JOINS \ PRE=/mnt/assembly/vdj/current15 $* diff --git a/enclone/src/join.rs b/enclone/src/join.rs index a355ba4ab..08ad0aaff 100644 --- a/enclone/src/join.rs +++ b/enclone/src/join.rs @@ -104,7 +104,7 @@ pub fn join_exacts( if !ctl.silent { println!("comparing {} simple clonotypes", info.len()); } - ctl.perf_stats(&timer1, "join setup"); + let timer2 = Instant::now(); let joinf = |r: &mut ( @@ -601,7 +601,6 @@ pub fn join_exacts( results.par_iter_mut().for_each(joinf); - ctl.perf_stats(&timer2, "in main part of join"); for r in &results { for &j in &r.5 { raw_joins.push((j.0 as i32, j.1 as i32)); diff --git a/enclone/src/join2.rs b/enclone/src/join2.rs index e91d160f3..0840e7ea5 100644 --- a/enclone/src/join2.rs +++ b/enclone/src/join2.rs @@ -90,6 +90,6 @@ pub fn finish_join( let bad_rate = percent_ratio(bads, denom); println!("whitelist contamination rate = {bad_rate:.2}%"); } - ctl.perf_stats(&timer3, "in tail of join"); + eq } diff --git a/enclone/src/misc1.rs b/enclone/src/misc1.rs index a5e50babe..1a4b4bbbe 100644 --- a/enclone/src/misc1.rs +++ b/enclone/src/misc1.rs @@ -10,7 +10,7 @@ use equiv::EquivRel; use itertools::Itertools; #[cfg(not(target_os = "windows"))] use pager::Pager; -use perf_stats::elapsed; + use std::collections::HashMap; use std::time::Instant; use string_utils::stringme; @@ -161,7 +161,7 @@ pub fn lookup_heavy_chain_reuse( } println!( "\nused {:.2} seconds in heavy chain reuse calculation\n", - elapsed(&t) + t.elapsed().as_secs_f64() ); } } diff --git a/enclone/src/misc2.rs b/enclone/src/misc2.rs index fa7375bf8..7d6d3d010 100644 --- a/enclone/src/misc2.rs +++ b/enclone/src/misc2.rs @@ -321,7 +321,7 @@ pub fn find_exact_subclonotypes( groups.push((r, s)); r = s; } - ctl.perf_stats(&t, "finding exact subclonotypes one"); + let t = Instant::now(); let mut results = Vec::<( usize, @@ -423,7 +423,7 @@ pub fn find_exact_subclonotypes( res.1.push(ExactClonotype { share, clones }); } }); - ctl.perf_stats(&t, "finding exact subclonotypes two"); + let t = Instant::now(); let mut max_exact = 0; for i in 0..results.len() { @@ -519,7 +519,7 @@ pub fn find_exact_subclonotypes( } println!(); } - ctl.perf_stats(&t, "finding exact subclonotypes three"); + exact_clonotypes } diff --git a/enclone_args/src/load_gex.rs b/enclone_args/src/load_gex.rs index 14ebd372f..d17d8bbe8 100644 --- a/enclone_args/src/load_gex.rs +++ b/enclone_args/src/load_gex.rs @@ -132,7 +132,6 @@ pub fn get_gex_info(ctl: &mut EncloneControl) -> Result { .collect() }) .collect(); - ctl.perf_stats(&t, "after load_gex"); // Answer. diff --git a/enclone_args/src/load_gex_core.rs b/enclone_args/src/load_gex_core.rs index f0b3b097e..af156c5b1 100644 --- a/enclone_args/src/load_gex_core.rs +++ b/enclone_args/src/load_gex_core.rs @@ -554,7 +554,6 @@ pub fn load_gex( for (_, r) in &results { ctl.pathlist.extend(r.f15.iter().cloned()); } - ctl.perf_stats(&t, "in load_gex main loop"); // Test for error. @@ -631,6 +630,5 @@ pub fn load_gex( // Done. - ctl.perf_stats(&t, "in load_gex tail"); Ok(()) } diff --git a/enclone_args/src/proc_args.rs b/enclone_args/src/proc_args.rs index 6a2552356..f9795ba4e 100644 --- a/enclone_args/src/proc_args.rs +++ b/enclone_args/src/proc_args.rs @@ -500,7 +500,6 @@ pub fn proc_args(ctl: &mut EncloneControl, args: &[String]) -> Result<(), String "UMI_RATIO_FILT_MARK", &mut ctl.clono_filt_opt_def.umi_ratio_filt_mark, ), - ("UNACCOUNTED", &mut ctl.perf_opt.unaccounted), ("UTR_CON", &mut ctl.gen_opt.utr_con), ("VDUP", &mut ctl.clono_filt_opt.vdup), ("VIS_DUMP", &mut ctl.gen_opt.vis_dump), @@ -646,9 +645,6 @@ pub fn proc_args(ctl: &mut EncloneControl, args: &[String]) -> Result<(), String let set_nothing_simple = [ "CELLRANGER", - "COMP", - "COMPE", - "COMP2", "DUMP_INTERNAL_IDS", "EVIL_EYE", "FORCE_EXTERNAL", @@ -938,8 +934,6 @@ pub fn proc_args(ctl: &mut EncloneControl, args: &[String]) -> Result<(), String // Record time. - ctl.perf_stats(&targs, "in main args loop"); - // Do residual argument processing. if ctl.gen_opt.internal_run && ctl.gen_opt.config.is_empty() { diff --git a/enclone_args/src/proc_args2.rs b/enclone_args/src/proc_args2.rs index 5b8935607..49de3c519 100644 --- a/enclone_args/src/proc_args2.rs +++ b/enclone_args/src/proc_args2.rs @@ -259,6 +259,6 @@ pub fn proc_args_tail(ctl: &mut EncloneControl, args: &[String]) -> Result<(), S } } } - ctl.perf_stats(&tall, "in proc_args_tail"); + Ok(()) } diff --git a/enclone_args/src/proc_args3.rs b/enclone_args/src/proc_args3.rs index 0b6f7c78a..24a7a9af8 100644 --- a/enclone_args/src/proc_args3.rs +++ b/enclone_args/src/proc_args3.rs @@ -507,7 +507,7 @@ pub fn proc_xcr( other's structure.\n" )); } - ctl.perf_stats(&t, "in proc_xcr 1"); + let t = Instant::now(); for (id, d) in donor_groups.iter().enumerate() { let origin_groups = if ctl.gen_opt.cellranger { @@ -609,7 +609,6 @@ pub fn proc_xcr( } } } - ctl.perf_stats(&t, "in proc_xcr 2"); // Get paths. This will need to change when cellranger switches to multi. This code is // parallelized because this code can indirectly make many calls to path_exists, and the wall @@ -641,7 +640,7 @@ pub fn proc_xcr( } } } - ctl.perf_stats(&t, "in proc_xcr 3"); + let t = Instant::now(); let spinlock: Arc = Arc::new(AtomicUsize::new(0)); results.par_iter_mut().for_each(|res| { @@ -688,7 +687,7 @@ pub fn proc_xcr( ctl.origin_info.dataset_path.push(result.0); ctl.origin_info.gex_path.push(result.1); } - ctl.perf_stats(&t, "in proc_xcr 4"); + Ok(()) } diff --git a/enclone_args/src/proc_args_check.rs b/enclone_args/src/proc_args_check.rs index 9f8465e24..2a3985dfb 100644 --- a/enclone_args/src/proc_args_check.rs +++ b/enclone_args/src/proc_args_check.rs @@ -778,12 +778,12 @@ pub fn check_lvars(ctl: &EncloneControl, gex_info: &GexInfo) -> Result<(), Strin to_check.push(x.clone()); } } - ctl.perf_stats(&t, "checking lvars top"); + let t = Instant::now(); if !to_check.is_empty() { check_gene_fb(ctl, gex_info, &to_check, "lead")?; } - ctl.perf_stats(&t, "checking gene"); + Ok(()) } diff --git a/enclone_args/src/proc_args_post.rs b/enclone_args/src/proc_args_post.rs index b0a0ea350..1f12161ea 100644 --- a/enclone_args/src/proc_args_post.rs +++ b/enclone_args/src/proc_args_post.rs @@ -488,7 +488,6 @@ pub fn proc_args_post( .to_string(), ); } - ctl.perf_stats(&t, "after main args loop 1"); // Process TCR, BCR and META. @@ -515,7 +514,7 @@ pub fn proc_args_post( .collect(); proc_meta_core(&lines, ctl)?; } - ctl.perf_stats(&t, "in proc_meta"); + if !xcrs.is_empty() { let arg = &xcrs[xcrs.len() - 1]; proc_xcr(arg, gex, bc, have_gex, ctl)?; @@ -669,7 +668,7 @@ pub fn proc_args_post( ctl.clono_filt_opt_def.donor = true; } } - ctl.perf_stats(&t, "after main args loop 2"); + proc_args_tail(ctl, args)?; // Sort chains_to_align. diff --git a/enclone_core/Cargo.toml b/enclone_core/Cargo.toml index e92329900..2be3904c3 100644 --- a/enclone_core/Cargo.toml +++ b/enclone_core/Cargo.toml @@ -31,7 +31,6 @@ evalexpr = ">=7, <12" io_utils = { path = "../io_utils" } itertools.workspace = true lazy_static = "1" -perf_stats = { path = "../perf_stats" } qd = { git = "https://github.com/Barandis/qd" } rayon = "1" regex = { version = "1", default-features = false, features = ["std", "perf"] } diff --git a/enclone_core/src/defs.rs b/enclone_core/src/defs.rs index 5dabd4976..407132063 100644 --- a/enclone_core/src/defs.rs +++ b/enclone_core/src/defs.rs @@ -7,10 +7,6 @@ use evalexpr::Node; use hdf5::Dataset; use io_utils::{open_for_read, path_exists}; -use perf_stats::elapsed; - -#[cfg(not(target_os = "windows"))] -use perf_stats::peak_mem_usage_gb; use regex::Regex; use std::cmp::max; @@ -496,108 +492,34 @@ pub struct ParseableOpt { pub pno_header: bool, // suppress header line } -// Computational performance options. - -#[derive(Default, PartialEq, Eq)] -pub struct PerfOpt { - pub comp: bool, // print computational performance stats - pub comp2: bool, // print more detailed computational performance stats - pub unaccounted: bool, // show unaccounted time at each step - pub comp_enforce: bool, // comp plus enforce no unaccounted time -} - // Set up control datastructure (EncloneControl). This is stuff that is constant for a given // run of enclone. If you add something to this, be sure to update the "changed" section in // enclone_server.rs, if needed. #[derive(Default)] pub struct EncloneControl { - pub perf_opt: PerfOpt, // computational performance options - pub start_time: Option, // enclone start time - pub gen_opt: GeneralOpt, // miscellaneous general options - pub plot_opt: PlotOpt, // plot options - pub pretty: bool, // use escape characters to enhance view - pub nogray: bool, // don't gray in per cell lines - pub silent: bool, // turn off extra logging - pub force: bool, // make joins even if redundant - pub debug_table_printing: bool, // turn on debugging for table printing - pub merge_all_impropers: bool, // merge all improper exact subclonotypes - pub heur: ClonotypeHeuristics, // algorithmic heuristics - pub origin_info: OriginInfo, // origin (sample) info - pub allele_alg_opt: AlleleAlgOpt, // algorithmic options for allele finding - pub allele_print_opt: AllelePrintOpt, // print options for allele finding - pub join_alg_opt: JoinAlgOpt, // algorithmic options for join - pub join_print_opt: JoinPrintOpt, // printing options for join operations + pub start_time: Option, // enclone start time + pub gen_opt: GeneralOpt, // miscellaneous general options + pub plot_opt: PlotOpt, // plot options + pub pretty: bool, // use escape characters to enhance view + pub nogray: bool, // don't gray in per cell lines + pub silent: bool, // turn off extra logging + pub force: bool, // make joins even if redundant + pub debug_table_printing: bool, // turn on debugging for table printing + pub merge_all_impropers: bool, // merge all improper exact subclonotypes + pub heur: ClonotypeHeuristics, // algorithmic heuristics + pub origin_info: OriginInfo, // origin (sample) info + pub allele_alg_opt: AlleleAlgOpt, // algorithmic options for allele finding + pub allele_print_opt: AllelePrintOpt, // print options for allele finding + pub join_alg_opt: JoinAlgOpt, // algorithmic options for join + pub join_print_opt: JoinPrintOpt, // printing options for join operations pub clono_filt_opt_def: ClonoFiltOptDefault, // default filtering options for clonotypes - pub clono_filt_opt: ClonoFiltOpt, // filtering options for clonotypes - pub clono_print_opt: ClonoPrintOpt, // printing options for clonotypes - pub clono_group_opt: ClonoGroupOpt, // grouping options for clonotypes - pub parseable_opt: ParseableOpt, // parseable output options - pub pathlist: Vec, // list of input files - pub last_modified: Vec, // last modified for pathlist -} - -pub static mut WALLCLOCK: f64 = 0.0; -pub static mut LAST_IPEAK: f64 = -0.0; - -impl EncloneControl { - pub fn perf_stats(&self, t: &Instant, msg: &str) { - let used = elapsed(t); - let t2 = Instant::now(); - #[allow(unused_mut)] - let mut usedx = String::new(); - #[cfg(not(target_os = "windows"))] - { - if self.perf_opt.comp { - let peak = peak_mem_usage_gb(); - let ipeak = (100.0 * peak).round(); - let peak_mem = format!("peak mem = {peak:.2} GB"); - usedx = format!("{used:.2}"); - let mut ipeak_changed = false; - unsafe { - if ipeak != LAST_IPEAK { - ipeak_changed = true; - LAST_IPEAK = ipeak; - } - } - if usedx != "0.00" || ipeak_changed { - println!("used {usedx} seconds {msg}, {peak_mem}"); - } - } - } - - // Check for time used in the above computation, which could otherwise introduce a - // discrepancy into the time accounting stats. Surprisingly, the time spent in that - // section can be nontrivial. - - let used2 = elapsed(&t2); - let used2x = format!("{used2:.2}"); - if self.perf_opt.comp && used2x != "0.00" { - println!("used {used2x} seconds computing perf stats for {msg}"); - } - - // Update total time used. - - unsafe { - WALLCLOCK += used + used2; - } - - // Report unaccounted time. - - if self.perf_opt.comp && self.perf_opt.unaccounted && msg != "total" { - let delta; - unsafe { - delta = elapsed(&self.start_time.unwrap()) - WALLCLOCK; - } - let deltas = format!("{delta:.2}"); - if deltas != "0.00" { - if usedx == "0.00" { - println!("used 0.00 seconds {msg}"); - } - println!("used {deltas} seconds unaccounted for"); - } - } - } + pub clono_filt_opt: ClonoFiltOpt, // filtering options for clonotypes + pub clono_print_opt: ClonoPrintOpt, // printing options for clonotypes + pub clono_group_opt: ClonoGroupOpt, // grouping options for clonotypes + pub parseable_opt: ParseableOpt, // parseable output options + pub pathlist: Vec, // list of input files + pub last_modified: Vec, // last modified for pathlist } // Set up data structure to track clonotype data. A TigData is for one contig; diff --git a/enclone_stuff/src/disintegrate.rs b/enclone_stuff/src/disintegrate.rs index ce0a24315..b5c67af9f 100644 --- a/enclone_stuff/src/disintegrate.rs +++ b/enclone_stuff/src/disintegrate.rs @@ -67,7 +67,7 @@ pub fn disintegrate_onesies( } } } - ctl.perf_stats(&t, "disintegrating onesies 1"); + let t = Instant::now(); *join_info = join_info2; *exact_clonotypes = exacts2; @@ -91,7 +91,7 @@ pub fn disintegrate_onesies( } to_info2.push(x); } - ctl.perf_stats(&t, "disintegrating onesies 2"); + let t = Instant::now(); *info = info2; let mut raw_joins2 = Vec::<(i32, i32)>::new(); @@ -119,6 +119,5 @@ pub fn disintegrate_onesies( } } *eq = eq2; - ctl.perf_stats(&t, "disintegrating onesies 3"); } } diff --git a/enclone_stuff/src/doublets.rs b/enclone_stuff/src/doublets.rs index 10dd3671b..753a7a2c9 100644 --- a/enclone_stuff/src/doublets.rs +++ b/enclone_stuff/src/doublets.rs @@ -42,7 +42,7 @@ pub fn delete_doublets( results.push((i, Vec::new())); } let mut pures = Vec::>::new(); - ctl.perf_stats(&t, "doublet filtering setup"); + let t = Instant::now(); results.par_iter_mut().for_each(|res| { let i = res.0; @@ -99,7 +99,6 @@ pub fn delete_doublets( // Find the pairs of pure subclonotypes that share identical CDR3 sequences. - ctl.perf_stats(&t, "doublet filtering main"); let t = Instant::now(); let mut shares = Vec::<(usize, usize)>::new(); { @@ -114,7 +113,7 @@ pub fn delete_doublets( } content.par_sort(); content.dedup(); - ctl.perf_stats(&t, "doublet filtering shares setup"); + let t = Instant::now(); let mut j = 0; while j < content.len() { @@ -129,7 +128,6 @@ pub fn delete_doublets( } shares.par_sort(); shares.dedup(); - ctl.perf_stats(&t, "doublet filtering shares"); } // Find triples of pure subclonotypes in which the first two have no share, but both @@ -185,7 +183,6 @@ pub fn delete_doublets( trips.append(&mut r.1); } } - ctl.perf_stats(&t, "doublet filtering trips"); // Delete some of the third members of the triples. @@ -248,6 +245,5 @@ pub fn delete_doublets( orbits2.push(o); } *orbits = orbits2; - ctl.perf_stats(&t, "doublet filtering tail"); } } diff --git a/enclone_stuff/src/fcell.rs b/enclone_stuff/src/fcell.rs index be60e3142..c59afeddd 100644 --- a/enclone_stuff/src/fcell.rs +++ b/enclone_stuff/src/fcell.rs @@ -99,7 +99,6 @@ pub fn filter_by_fcell( res.2 = ind_readers[li].as_ref().unwrap().read_raw().unwrap(); } }); - ctl.perf_stats(&tdi, "setting up readers, zero"); // Proceed. diff --git a/enclone_stuff/src/inconsistent.rs b/enclone_stuff/src/inconsistent.rs index 2f2000f6f..68b79225a 100644 --- a/enclone_stuff/src/inconsistent.rs +++ b/enclone_stuff/src/inconsistent.rs @@ -124,6 +124,6 @@ pub fn test_vdj_gex_inconsistent( the argument ALLOW_INCONSISTENT to the command line.\n", ); } - ctl.perf_stats(&tinc, "testing for inconsistency"); + Ok(()) } diff --git a/enclone_stuff/src/some_filters.rs b/enclone_stuff/src/some_filters.rs index 14bda3894..5d31edb12 100644 --- a/enclone_stuff/src/some_filters.rs +++ b/enclone_stuff/src/some_filters.rs @@ -186,13 +186,11 @@ pub fn some_filters( orbits2.push(o); } *orbits = orbits2; - ctl.perf_stats(&tsig, "signature filtering"); // Merge onesies where totally unambiguous. let tmerge = Instant::now(); merge_onesies(orbits, ctl, exact_clonotypes, info, eq, disintegrated); - ctl.perf_stats(&tmerge, "merging onesies"); // Check for disjoint orbits. @@ -209,7 +207,6 @@ pub fn some_filters( refdata, dref, ); - ctl.perf_stats(&tsplit, "splitting orbits 1"); // Test for weak chains. @@ -227,7 +224,6 @@ pub fn some_filters( refdata, dref, ); - ctl.perf_stats(&tweak, "weak chain filtering"); // Check for disjoint orbits (again). @@ -244,7 +240,6 @@ pub fn some_filters( refdata, dref, ); - ctl.perf_stats(&tsplit, "splitting orbits 2"); // Find and mark for deletion exact subclonotypes having a variant base in V..J that, // accounting for all the cells in all the exact subclonotypes, never occurs as Q60 @@ -449,5 +444,4 @@ pub fn some_filters( dref, ); // *orbits = orbits.iter().flatten().map(|x| vec![*x]).collect(); - ctl.perf_stats(&tsplit, "splitting orbits 3"); } diff --git a/enclone_stuff/src/start.rs b/enclone_stuff/src/start.rs index 52ae52f93..8eff7d561 100644 --- a/enclone_stuff/src/start.rs +++ b/enclone_stuff/src/start.rs @@ -116,7 +116,6 @@ pub fn main_enclone_start(setup: EncloneSetup) -> Result::new(); let mut broken = Vec::::new(); flag_defective(ctl, refdata, &mut log, &mut broken); - ctl.perf_stats(&tr, "flagging defective references"); // Parse the json annotations file. @@ -129,7 +128,6 @@ pub fn main_enclone_start(setup: EncloneSetup) -> Result Result Result Result = build_info(refdata, ctl, &mut exact_clonotypes, &mut fate); - ctl.perf_stats(&tinfo, "building info"); // Derive consensus sequences for alternate alleles of V segments. Then create donor // reference sequences for Loupe. @@ -300,7 +294,7 @@ pub fn main_enclone_start(setup: EncloneSetup) -> Result Result Result Result Result Result Result Result<(), St } } unique_sort(&mut vars); - ctl.perf_stats(&tstar, "doing miscellaneous stuff"); + let tomega = Instant::now(); for x in vars.iter() { for (iy, y) in ends.iter().enumerate() { @@ -122,6 +122,6 @@ pub fn match_vars(ctl: &mut EncloneControl, gex_info: &GexInfo) -> Result<(), St } } } - ctl.perf_stats(&tomega, "messing with variables"); + Ok(()) } diff --git a/equiv/src/lib.rs b/equiv/src/lib.rs index 1196b78b9..c5d8169ab 100644 --- a/equiv/src/lib.rs +++ b/equiv/src/lib.rs @@ -200,7 +200,7 @@ impl EquivRel { let delta_peak = peak_mem_usage_bytes() - peak; println!( - "{} seconds used, delta peak mem = {} bytes", elapsed(&t), delta_peak ); + "{} seconds used, delta peak mem = {} bytes", t.elapsed().as_secs_f64(), delta_peak ); */ diff --git a/perf_stats/Cargo.toml b/perf_stats/Cargo.toml deleted file mode 100644 index 683a31d53..000000000 --- a/perf_stats/Cargo.toml +++ /dev/null @@ -1,13 +0,0 @@ -[package] -name = "perf_stats" -version = "0.1.8" -authors = ["David Jaffe "] -license = "MIT" -description = "Some tools that are 'internal' for now because they are insufficiently refined and unstable, but which are used by other 'public' crates." -edition = "2018" -repository = "https://github.com/10XGenomics/enclone_ranger" - -[dependencies] -io_utils = { path = "../io_utils" } -libc = "0.2" -string_utils = { path = "../string_utils" } diff --git a/perf_stats/LICENSE b/perf_stats/LICENSE deleted file mode 100644 index dbe7eeee4..000000000 --- a/perf_stats/LICENSE +++ /dev/null @@ -1,21 +0,0 @@ -The MIT License (MIT) - -Copyright (c) 2018-2020 10x Genomics, Inc. - -Permission is hereby granted, free of charge, to any person obtaining a copy -of this software and associated documentation files (the "Software"), to deal -in the Software without restriction, including without limitation the rights -to use, copy, modify, merge, publish, distribute, sublicense, and/or sell -copies of the Software, and to permit persons to whom the Software is -furnished to do so, subject to the following conditions: - -The above copyright notice and this permission notice shall be included in -all copies or substantial portions of the Software. - -THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR -IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, -FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE -AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER -LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, -OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN -THE SOFTWARE. diff --git a/perf_stats/README.md b/perf_stats/README.md deleted file mode 100644 index 256011781..000000000 --- a/perf_stats/README.md +++ /dev/null @@ -1 +0,0 @@ -This crate contains some utilities. The interface for these could be changed. diff --git a/perf_stats/src/lib.rs b/perf_stats/src/lib.rs deleted file mode 100644 index d75d8eca7..000000000 --- a/perf_stats/src/lib.rs +++ /dev/null @@ -1,276 +0,0 @@ -// Copyright (c) 2018 10X Genomics, Inc. All rights reserved. - -// Computational performance stats. - -use io_utils::dir_list; - -#[cfg(not(target_os = "windows"))] -use libc::{getuid, rusage, RLIMIT_NPROC}; - -#[cfg(not(target_os = "windows"))] -use libc::{rlimit, setrlimit}; - -use std::{ - cmp::min, - fs::File, - io::{BufRead, BufReader}, - process::id, - time::Instant, -}; -use string_utils::TextUtils; - -// Find elapsed time. Usage example: -// let t = Instant::now( ); -// .. do something .. -// println!( "{} seconds used doing such and such", elapsed(&t) ); - -pub fn elapsed(start: &Instant) -> f64 { - let d = start.elapsed(); - d.as_secs() as f64 + d.subsec_nanos() as f64 / 1e9 -} - -// Report number of threads in use. - -pub fn nthreads() -> i64 { - let procfn = "/proc/self/status"; - let prob1 = "\nWARNING: nthreads() failed to access /proc status file.\n"; - let crap = "This suggests something is badly broken in the \ - operating environment.\nContinuing nonetheless, by returning -1."; - let f = std::fs::File::open(procfn); - match f { - Err(_) => println!("{prob1}{crap}"), - Ok(f) => { - let f = std::io::BufReader::new(f); - for line in f.lines() { - let s = line.unwrap(); - if s.starts_with("Threads:") { - let mut s = s.after("Threads:").to_string(); - s = s.replace('\t', ""); - s = s.replace(' ', ""); - return s.force_i64(); - } - } - } - }; - -1 -} - -// Set the maximum number of threads. This is intended as a debugging thing. -// If you think that at some point you're using too many threads, this gives you -// a way of finding it, by pre-capping the thread count. - -#[cfg(not(target_os = "windows"))] -pub fn set_max_threads(n: u64) { - unsafe { - let limit = rlimit { - rlim_cur: n, - rlim_max: n, - }; - let _ = setrlimit(RLIMIT_NPROC, &limit); - } -} - -// Report peak memory usage in bytes or gigabytes. For linux, this is determined by reading the -// proc filesystem. - -#[cfg(target_os = "linux")] -pub fn peak_mem_usage_bytes() -> i64 { - let procfn = "/proc/self/status"; - let prob1 = "\nWARNING: peak_mem_usage_bytes( ) failed to \ - access /proc status file.\n"; - let crap = "This suggests something is badly broken in the \ - operating environment.\nContinuing nonetheless, by returning -1."; - let f = std::fs::File::open(procfn); - match f { - Err(_) => println!("{}{}", prob1, crap), - Ok(f) => { - let f = std::io::BufReader::new(f); - for line in f.lines() { - let s = line.unwrap(); - if s.starts_with("VmHWM") { - let split: Vec<&str> = s.split_whitespace().collect(); - let printfail = |msg| { - println!( - "\nWARNING:\ - peak_mem_usage_bytes( ) encountered broken line in\ - /proc status file.\n{}\nLine = {}\n{}", - msg, s, crap - ) - }; - if split.len() != 3 { - printfail("Field count wrong."); - } else if split[2] != "kB" { - printfail("Bad units field."); - } else if split[1].parse::().is_err() { - printfail("Bad count field."); - } else { - return split[1].force_i64() * 1024; - } - break; - } - } - } - }; - -1 -} - -#[cfg(any(target_os = "macos", target_os = "ios"))] -pub fn peak_mem_usage_bytes() -> i64 { - let maxrss_slf; - unsafe { - let mut rusage: libc::rusage = std::mem::zeroed(); - let retval = libc::getrusage(libc::RUSAGE_SELF, &mut rusage as *mut _); - assert_eq!(retval, 0); - maxrss_slf = rusage.ru_maxrss; - } - maxrss_slf -} - -#[cfg(any(target_os = "macos", target_os = "ios", target_os = "linux"))] -pub fn peak_mem_usage_gb() -> f64 { - peak_mem_usage_bytes() as f64 / ((1024 * 1024 * 1024) as f64) -} - -// Report available memory gigabytes. - -pub fn available_mem_gb() -> Option { - let procfn = "/proc/meminfo"; - // let mut bytes : i64 = -1; - let f = std::fs::File::open(procfn); - match f { - Err(_) => None, - Ok(f) => { - let f = std::io::BufReader::new(f); - for line in f.lines() { - let s = line.unwrap(); - if s.starts_with("MemAvailable") { - let split: Vec<&str> = s.split_ascii_whitespace().collect(); - if split.len() != 3 || split[2] != "kB" { - return None; - } - return Some(split[1].parse::().ok()? as f64 / (1024_f64 * 1024_f64)); - } - } - None - } - } -} - -// Report getrusage stats. - -#[cfg(not(target_os = "windows"))] -pub fn getrusage() -> rusage { - use std::mem::MaybeUninit; - let usage: rusage = unsafe { MaybeUninit::zeroed().assume_init() }; - usage -} - -// Return current memory usage. - -pub fn mem_usage_bytes() -> i64 { - let procfn = "/proc/self/statm".to_string(); - let prob1 = "\nWARNING: mem_usage_bytes( ) failed to access /proc/self/statm.\n"; - let crap = "This suggests something is badly broken in the \ - operating environment.\nContinuing nonetheless, by returning -1."; - let f = std::fs::File::open(procfn); - match f { - Err(_) => println!("{prob1}{crap}"), - Ok(f) => { - let f = std::io::BufReader::new(f); - if let Some(line) = f.lines().next() { - let s = line.unwrap(); - let fields: Vec<&str> = s.split_whitespace().collect(); - // ◼ The page size should not be hardcoded. - let page_size = 4096_i64; - return fields[1].force_i64() * page_size; - } - } - }; - -1_i64 -} - -pub fn mem_usage_gb() -> f64 { - mem_usage_bytes() as f64 / ((1024 * 1024 * 1024) as f64) -} - -// Report the status of all processes having the same owner as 'this' process, -// showing the parent process id, the process id, its memory use in GB (RSS), -// and the command, which is folder. - -#[cfg(not(target_os = "windows"))] -pub fn ps_me() { - let uid = unsafe { getuid() } as i64; - println!( - "\nPROCESSES HAVING THE SAME OWNER (UID={}) AS THIS PROCESS = {}\n", - uid, - id() - ); - let procs = dir_list("/proc"); - println!("{:>6} {:>6} {:>7} CMD", "PPID", "PID", "GB"); - const RIGHT: usize = 60; - 'outer: for i in 0..procs.len() { - if procs[i].parse::().is_err() { - continue; - } - let (mut pid, mut ppid) = (-1_i64, -1_i64); - let mut rss = -1_f64; - let mut cmd = String::new(); - let f = format!("/proc/{}/status", procs[i]); - let f = File::open(&f); - if f.is_err() { - continue; - } - let f = f.unwrap(); - let f = BufReader::new(f); - for line in f.lines() { - if line.is_err() { - continue 'outer; - } // fail that does occur rarely - let s = line.unwrap(); - if s.starts_with("Uid:\t") { - let this_uid = s.after("Uid:\t").before("\t").force_i64(); - if this_uid != uid { - continue 'outer; - } - } else if s.starts_with("Pid:\t") { - pid = s.after("Pid:\t").force_i64(); - } else if s.starts_with("PPid:\t") { - ppid = s.after("PPid:\t").force_i64(); - } else if s.starts_with("VmRSS:\t") { - let t = s.after("VmRSS:\t"); - let t = t.to_string().replace(' ', ""); - rss = t.before("k").force_f64() / (1024 * 1024) as f64; - } - } - let f = format!("/proc/{}/cmdline", procs[i]); - let f = File::open(&f); - if f.is_err() { - continue; - } - let f = f.unwrap(); - let f = BufReader::new(f); - if let Some(line) = f.lines().next() { - if line.is_err() { - continue 'outer; - } // fail that does occur rarely - cmd = line.unwrap(); - cmd = cmd.replace('', " "); - } - if cmd.len() <= RIGHT { - println!("{ppid:6} {pid:6} {rss:7.2} {cmd}"); - } else { - let mut start = 0; - while start < cmd.len() { - let stop = min(start + RIGHT, cmd.len()); - if start == 0 { - let c = &cmd[0..stop]; - println!("{ppid:6} {pid:6} {rss:7.2} {c}"); - } else { - let c = &cmd[start..stop]; - println!(" {c}"); - } - start += RIGHT; - } - } - } -} diff --git a/vdj_ann_ref/Cargo.toml b/vdj_ann_ref/Cargo.toml index 627263d16..cfcaf752d 100644 --- a/vdj_ann_ref/Cargo.toml +++ b/vdj_ann_ref/Cargo.toml @@ -16,7 +16,6 @@ exons = { path = "../exons" } fasta_tools = { version = "0.1", path = "../fasta_tools" } flate2 = "1" io_utils = { path = "../io_utils" } -perf_stats = { path = "../perf_stats" } sha2 = ">=0.9.3, <0.11" string_utils = { path = "../string_utils" } diff --git a/vdj_ann_ref/src/bin/build_vdj_ref.rs b/vdj_ann_ref/src/bin/build_vdj_ref.rs index 6325df119..7d36a7810 100644 --- a/vdj_ann_ref/src/bin/build_vdj_ref.rs +++ b/vdj_ann_ref/src/bin/build_vdj_ref.rs @@ -84,7 +84,6 @@ use debruijn::{ }; use fasta_tools::load_genbank_accession; use flate2::read::MultiGzDecoder; -use perf_stats::elapsed; use process::Command; use sha2::{Digest, Sha256}; @@ -1199,7 +1198,10 @@ fn main() { // and it might be possible to speed it up. // ◼ Put this 'selective fasta loading' into its own function. - println!("{:.1} seconds used, loading fasta", elapsed(&t)); + println!( + "{:.1} seconds used, loading fasta", + t.elapsed().as_secs_f64() + ); let mut refs = Vec::::new(); let mut rheaders = Vec::::new(); let gz = MultiGzDecoder::new(std::fs::File::open(&fasta).unwrap()); @@ -1240,7 +1242,10 @@ fn main() { // Get the DNA sequences for the exons. - println!("{:.1} seconds used, getting exon seqs", elapsed(&t)); + println!( + "{:.1} seconds used, getting exon seqs", + t.elapsed().as_secs_f64() + ); let mut dna = Vec::::new(); for i in 0..exons.len() { let chr = &exons[i].2; @@ -1255,7 +1260,7 @@ fn main() { println!( "{:.1} seconds used, checking for nearly identical transcripts", - elapsed(&t) + t.elapsed().as_secs_f64() ); let mut to_delete = vec![false; exons.len()]; let mut i = 0; @@ -1310,7 +1315,10 @@ fn main() { // Build fasta. - println!("{:.1} seconds used, building fasta", elapsed(&t)); + println!( + "{:.1} seconds used, building fasta", + t.elapsed().as_secs_f64() + ); let mut i = 0; let mut record = 0; while i < exons.len() { @@ -1521,7 +1529,10 @@ fn main() { // Add genes. - println!("{:.1} seconds used, adding genes", elapsed(&t)); + println!( + "{:.1} seconds used, adding genes", + t.elapsed().as_secs_f64() + ); for i in 0..added_genes.len() { add_gene( &mut out,