Command line: /home/administrator/SPAdes-3.13.0-Linux/bin/spades.py --rna -t 32 -o /DATA/markop/Pcitri_rnaspades/output --ss-rf --disable-gzip-output --pe1-fr --pe2-fr --pe3-fr --pe4-fr --pe1-1 /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R1.fastq.gz --pe1-2 /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R2.fastq.gz --pe1-s /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_orphans.R1.fastq.gz --pe2-1 /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R1.fastq.gz --pe2-2 /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R2.fastq.gz --pe2-s /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_orphans.R1.fastq.gz --pe3-1 /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R1.fastq.gz --pe3-2 /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R2.fastq.gz --pe3-s /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_orphans.R1.fastq.gz --pe4-1 /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R1.fastq.gz --pe4-2 /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R2.fastq.gz --pe4-s /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_orphans.R1.fastq.gz System information: SPAdes version: 3.13.0 Python version: 2.7.15 OS: Linux-4.13.0-41-generic-x86_64-with-debian-stretch-sid Output dir: /DATA/markop/Pcitri_rnaspades/output Mode: read error correction and assembling Debug mode is turned OFF Dataset parameters: RNA-seq mode Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R1.fastq.gz'] right reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R2.fastq.gz'] interlaced reads: not specified single reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_orphans.R1.fastq.gz'] merged reads: not specified Library number: 2, library type: paired-end orientation: fr left reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R1.fastq.gz'] right reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R2.fastq.gz'] interlaced reads: not specified single reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_orphans.R1.fastq.gz'] merged reads: not specified Library number: 3, library type: paired-end orientation: fr left reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R1.fastq.gz'] right reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R2.fastq.gz'] interlaced reads: not specified single reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_orphans.R1.fastq.gz'] merged reads: not specified Library number: 4, library type: paired-end orientation: fr left reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R1.fastq.gz'] right reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R2.fastq.gz'] interlaced reads: not specified single reads: ['/FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_orphans.R1.fastq.gz'] merged reads: not specified Read error correction parameters: Iterations: 1 PHRED offset will be auto-detected Corrected reads will NOT be compressed Assembly parameters: k: auto Repeat resolution is enabled Mismatch careful mode is turned OFF MismatchCorrector will be SKIPPED Coverage cutoff is turned OFF Other parameters: Dir for temp files: /DATA/markop/Pcitri_rnaspades/output/tmp Threads: 32 Memory limit (in Gb): 250 ======= SPAdes pipeline started. Log can be found here: /DATA/markop/Pcitri_rnaspades/output/spades.log /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R2.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R1.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_orphans.R1.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R2.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R1.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_orphans.R1.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R2.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R1.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_orphans.R1.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R2.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R1.fastq.gz: max reads length: 150 /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_orphans.R1.fastq.gz: max reads length: 150 Reads length: 150 K values to be used: [49, 73] ===== Read error correction started. == Running read error correction tool: /home/administrator/SPAdes-3.13.0-Linux/bin/spades-hammer /DATA/markop/Pcitri_rnaspades/output/corrected/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 75) Starting BayesHammer, built from refs/heads/spades_3.13.0, git revision 8ea46659e9b2aca35444a808db550ac333006f8b 0:00:00.000 4M / 4M INFO General (main.cpp : 76) Loading config from /DATA/markop/Pcitri_rnaspades/output/corrected/configs/config.info 0:00:00.001 4M / 4M INFO General (main.cpp : 78) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.001 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 86) Trying to determine PHRED offset 0:00:00.002 4M / 4M INFO General (main.cpp : 92) Determined value is 33 0:00:00.002 4M / 4M INFO General (hammer_tools.cpp : 36) Hamming graph threshold tau=1, k=21, subkmer positions = [ 0 10 ] 0:00:00.002 4M / 4M INFO General (main.cpp : 113) Size of aux. kmer data 24 bytes === ITERATION 0 begins === 0:00:00.002 4M / 4M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:00.002 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:00:00.003 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.003 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60413 Gb 0:00:00.003 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:00.102 17G / 17G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R1.fastq.gz 0:01:12.243 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 7425927 reads 0:02:15.660 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 14860680 reads 0:03:18.385 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 22196469 reads 0:04:19.585 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 29491328 reads 0:04:45.634 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 32561049 reads 0:04:45.634 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R2.fastq.gz 0:05:48.674 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 40173588 reads 0:06:51.015 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 47889089 reads 0:07:53.836 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 55488735 reads 0:08:56.334 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 63088871 reads 0:09:13.617 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 65122098 reads 0:09:13.617 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_orphans.R1.fastq.gz 0:10:08.997 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 72797064 reads 0:10:08.997 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R1.fastq.gz 0:11:11.134 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 80136589 reads 0:14:21.172 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R2.fastq.gz 0:18:31.112 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_orphans.R1.fastq.gz 0:19:09.241 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 138149995 reads 0:19:09.242 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R1.fastq.gz 0:24:09.111 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R2.fastq.gz 0:29:01.625 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_orphans.R1.fastq.gz 0:29:44.110 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R1.fastq.gz 0:34:25.960 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R2.fastq.gz 0:37:41.712 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 272739462 reads 0:39:04.186 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_orphans.R1.fastq.gz 0:40:02.414 17G / 18G INFO K-mer Splitting (kmer_data.cpp : 112) Total 290817542 reads processed 0:40:03.893 128M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:40:39.603 128M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 891404860 kmers in total. 0:40:39.603 128M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:40:58.064 128M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:41:34.642 584M / 18G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:42:54.117 584M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 413354612 bytes occupied (3.70969 bits per kmer). 0:42:54.119 580M / 18G INFO K-mer Counting (kmer_data.cpp : 356) Arranging kmers in hash map order 0:43:33.059 13G / 18G INFO General (main.cpp : 148) Clustering Hamming graph. 1:04:09.530 13G / 18G INFO General (main.cpp : 155) Extracting clusters 1:12:52.618 13G / 34G INFO General (main.cpp : 167) Clustering done. Total clusters: 361604816 1:12:53.105 7G / 34G INFO K-mer Counting (kmer_data.cpp : 376) Collecting K-mer information, this takes a while. 1:13:03.820 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R1.fastq.gz 1:19:06.955 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R2.fastq.gz 1:24:46.237 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_orphans.R1.fastq.gz 1:25:48.679 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R1.fastq.gz 1:31:15.431 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R2.fastq.gz 1:36:25.984 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_orphans.R1.fastq.gz 1:37:10.005 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R1.fastq.gz 1:43:40.179 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R2.fastq.gz 1:49:50.551 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_orphans.R1.fastq.gz 1:50:39.561 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R1.fastq.gz 1:56:48.695 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R2.fastq.gz 2:02:42.475 27G / 34G INFO K-mer Counting (kmer_data.cpp : 382) Processing /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_orphans.R1.fastq.gz 2:03:49.646 27G / 34G INFO K-mer Counting (kmer_data.cpp : 389) Collection done, postprocessing. 2:03:53.431 27G / 34G INFO K-mer Counting (kmer_data.cpp : 403) There are 891404860 kmers in total. Among them 473906484 (53.164%) are singletons. 2:03:53.431 27G / 34G INFO General (main.cpp : 173) Subclustering Hamming graph 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 649) Subclustering done. Total 28385 non-read kmers were generated. 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 650) Subclustering statistics: 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 651) Total singleton hamming clusters: 282386932. Among them 240396012 (85.13%) are good 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 652) Total singleton subclusters: 6846541. Among them 6839051 (99.8906%) are good 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 653) Total non-singleton subcluster centers: 92188507. Among them 82916269 (89.9421%) are good 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 654) Average size of non-trivial subcluster: 6.60686 kmers 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 655) Average number of sub-clusters per non-singleton cluster: 1.25016 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 656) Total solid k-mers: 330151332 2:20:33.732 27G / 34G INFO Hamming Subclustering (kmer_cluster.cpp : 657) Substitution probabilities: [4,4]((0.929792,0.0229334,0.0270815,0.0201928),(0.0267959,0.931273,0.0130129,0.0289187),(0.0280339,0.012783,0.931837,0.0273463),(0.0198567,0.0268752,0.0228048,0.930463)) 2:20:34.183 27G / 34G INFO General (main.cpp : 178) Finished clustering. 2:20:34.183 27G / 34G INFO General (main.cpp : 197) Starting solid k-mers expansion in 32 threads. 2:52:07.184 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 0 produced 72117644 new k-mers. 3:23:24.352 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 1 produced 7016259 new k-mers. 3:54:58.187 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 2 produced 572329 new k-mers. 4:26:09.527 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 3 produced 127284 new k-mers. 4:57:26.035 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 4 produced 38836 new k-mers. 5:28:32.935 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 5 produced 13249 new k-mers. 5:59:48.107 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 6 produced 5474 new k-mers. 6:30:58.647 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 7 produced 2134 new k-mers. 7:02:01.487 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 8 produced 988 new k-mers. 7:33:10.723 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 9 produced 154 new k-mers. 8:04:12.935 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 10 produced 69 new k-mers. 8:35:19.011 27G / 34G INFO General (main.cpp : 218) Solid k-mers iteration 11 produced 0 new k-mers. 8:35:19.011 27G / 34G INFO General (main.cpp : 222) Solid k-mers finalized 8:35:19.011 27G / 34G INFO General (hammer_tools.cpp : 220) Starting read correction in 32 threads. 8:35:19.011 27G / 34G INFO General (hammer_tools.cpp : 233) Correcting pair of reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R1.fastq.gz and /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_paired.R2.fastq.gz 8:35:44.722 30G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 0 of 3200000 reads. 8:36:15.680 30G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 0 8:36:21.854 30G / 34G INFO General (hammer_tools.cpp : 185) Written batch 0 8:36:46.408 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 1 of 3200000 reads. 8:37:15.697 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 1 8:37:21.717 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 1 8:37:45.089 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 2 of 3200000 reads. 8:38:13.267 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 2 8:38:19.880 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 2 8:38:41.898 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 3 of 3200000 reads. 8:39:11.015 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 3 8:39:16.975 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 3 8:39:39.809 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 4 of 3200000 reads. 8:40:07.110 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 4 8:40:13.273 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 4 8:40:36.060 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 5 of 3200000 reads. 8:41:04.427 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 5 8:41:10.969 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 5 8:41:33.375 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 6 of 3200000 reads. 8:42:04.714 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 6 8:42:11.668 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 6 8:42:34.105 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 7 of 3200000 reads. 8:43:02.510 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 7 8:43:08.960 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 7 8:43:31.917 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 8 of 3200000 reads. 8:44:00.186 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 8 8:44:06.867 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 8 8:44:29.099 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 9 of 3200000 reads. 8:44:56.878 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 9 8:45:03.308 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 9 8:45:07.198 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 10 of 561049 reads. 8:45:13.310 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 10 8:45:14.466 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 10 8:45:18.464 27G / 34G INFO General (hammer_tools.cpp : 264) Correcting single reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S1_VF_2_GGAAGAGA-CGAGAGAA_L007_R1_trimmed_orphans.R1.fastq.gz 8:45:28.563 28G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 0 of 3200000 reads. 8:45:39.091 28G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 0 8:45:41.851 28G / 34G INFO General (hammer_tools.cpp : 136) Written batch 0 8:45:51.813 29G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 1 of 3200000 reads. 8:46:02.764 29G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 1 8:46:05.375 29G / 34G INFO General (hammer_tools.cpp : 136) Written batch 1 8:46:09.205 29G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 2 of 1274966 reads. 8:46:13.441 29G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 2 8:46:15.593 29G / 34G INFO General (hammer_tools.cpp : 136) Written batch 2 8:46:17.322 27G / 34G INFO General (hammer_tools.cpp : 233) Correcting pair of reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R1.fastq.gz and /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_paired.R2.fastq.gz 8:46:41.279 30G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 0 of 3200000 reads. 8:47:11.152 30G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 0 8:47:17.896 30G / 34G INFO General (hammer_tools.cpp : 185) Written batch 0 8:47:41.455 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 1 of 3200000 reads. 8:48:10.386 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 1 8:48:16.170 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 1 8:48:39.723 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 2 of 3200000 reads. 8:49:06.822 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 2 8:49:13.430 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 2 8:49:35.511 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 3 of 3200000 reads. 8:50:02.327 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 3 8:50:08.837 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 3 8:50:31.563 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 4 of 3200000 reads. 8:50:59.056 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 4 8:51:05.201 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 4 8:51:28.187 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 5 of 3200000 reads. 8:51:56.208 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 5 8:52:03.224 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 5 8:52:25.803 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 6 of 3200000 reads. 8:52:54.536 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 6 8:53:00.690 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 6 8:53:23.270 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 7 of 3200000 reads. 8:53:49.634 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 7 8:53:55.803 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 7 8:54:18.658 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 8 of 3200000 reads. 8:54:46.530 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 8 8:54:53.419 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 8 8:55:02.049 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 9 of 1196257 reads. 8:55:12.443 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 9 8:55:14.881 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 9 8:55:18.850 27G / 34G INFO General (hammer_tools.cpp : 264) Correcting single reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S2_VF_3_TCGGATTC-CGCAACTA_L007_R1_trimmed_orphans.R1.fastq.gz 8:55:28.986 28G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 0 of 3200000 reads. 8:55:39.290 28G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 0 8:55:42.412 28G / 34G INFO General (hammer_tools.cpp : 136) Written batch 0 8:55:49.267 29G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 1 of 2160417 reads. 8:55:56.107 29G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 1 8:55:58.429 29G / 34G INFO General (hammer_tools.cpp : 136) Written batch 1 8:55:59.964 27G / 34G INFO General (hammer_tools.cpp : 233) Correcting pair of reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R1.fastq.gz and /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_paired.R2.fastq.gz 8:56:24.222 30G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 0 of 3200000 reads. 8:56:51.504 30G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 0 8:56:57.617 30G / 34G INFO General (hammer_tools.cpp : 185) Written batch 0 8:57:21.651 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 1 of 3200000 reads. 8:57:48.881 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 1 8:57:55.828 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 1 8:58:18.757 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 2 of 3200000 reads. 8:58:46.904 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 2 8:58:53.406 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 2 8:59:16.474 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 3 of 3200000 reads. 8:59:43.686 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 3 8:59:50.516 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 3 9:00:13.142 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 4 of 3200000 reads. 9:00:40.304 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 4 9:00:46.463 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 4 9:01:09.482 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 5 of 3200000 reads. 9:01:37.374 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 5 9:01:44.500 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 5 9:02:06.830 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 6 of 3200000 reads. 9:02:35.505 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 6 9:02:42.218 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 6 9:03:05.225 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 7 of 3200000 reads. 9:03:33.976 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 7 9:03:40.836 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 7 9:04:03.525 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 8 of 3200000 reads. 9:04:32.415 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 8 9:04:38.883 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 8 9:05:01.668 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 9 of 3200000 reads. 9:05:28.942 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 9 9:05:35.343 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 9 9:05:58.317 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 10 of 3200000 reads. 9:06:25.726 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 10 9:06:32.840 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 10 9:06:35.805 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 11 of 423516 reads. 9:06:39.659 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 11 9:06:40.465 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 11 9:06:43.497 27G / 34G INFO General (hammer_tools.cpp : 264) Correcting single reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S3_VF_5_CTGTACCA-CACAGACT_L007_R1_trimmed_orphans.R1.fastq.gz 9:06:53.707 28G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 0 of 3200000 reads. 9:07:04.032 28G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 0 9:07:06.885 28G / 34G INFO General (hammer_tools.cpp : 136) Written batch 0 9:07:15.944 29G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 1 of 2762971 reads. 9:07:24.547 29G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 1 9:07:27.025 29G / 34G INFO General (hammer_tools.cpp : 136) Written batch 1 9:07:28.581 27G / 34G INFO General (hammer_tools.cpp : 233) Correcting pair of reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R1.fastq.gz and /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_paired.R2.fastq.gz 9:07:53.077 30G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 0 of 3200000 reads. 9:08:20.483 30G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 0 9:08:26.591 30G / 34G INFO General (hammer_tools.cpp : 185) Written batch 0 9:08:50.710 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 1 of 3200000 reads. 9:09:17.987 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 1 9:09:24.779 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 1 9:09:47.830 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 2 of 3200000 reads. 9:10:16.085 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 2 9:10:22.919 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 2 9:10:45.635 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 3 of 3200000 reads. 9:11:13.316 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 3 9:11:19.923 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 3 9:11:42.795 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 4 of 3200000 reads. 9:12:10.164 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 4 9:12:16.842 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 4 9:12:39.557 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 5 of 3200000 reads. 9:13:08.273 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 5 9:13:15.167 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 5 9:13:37.910 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 6 of 3200000 reads. 9:14:06.128 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 6 9:14:12.326 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 6 9:14:35.655 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 7 of 3200000 reads. 9:15:04.934 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 7 9:15:11.924 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 7 9:15:34.549 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 8 of 3200000 reads. 9:16:02.435 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 8 9:16:08.816 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 8 9:16:31.867 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 9 of 3200000 reads. 9:17:00.527 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 9 9:17:07.540 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 9 9:17:18.876 31G / 34G INFO General (hammer_tools.cpp : 168) Prepared batch 10 of 1641183 reads. 9:17:33.149 31G / 34G INFO General (hammer_tools.cpp : 175) Processed batch 10 9:17:36.414 31G / 34G INFO General (hammer_tools.cpp : 185) Written batch 10 9:17:40.008 27G / 34G INFO General (hammer_tools.cpp : 264) Correcting single reads: /FITO_ws/markop/pcitri_trimmed/PRO1976_S4_VF_6_GAGAGTAC-TGGAAGCA_L007_R1_trimmed_orphans.R1.fastq.gz 9:17:50.015 28G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 0 of 3200000 reads. 9:18:00.043 28G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 0 9:18:02.989 28G / 34G INFO General (hammer_tools.cpp : 136) Written batch 0 9:18:13.085 29G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 1 of 3200000 reads. 9:18:23.482 29G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 1 9:18:26.317 29G / 34G INFO General (hammer_tools.cpp : 136) Written batch 1 9:18:31.741 29G / 34G INFO General (hammer_tools.cpp : 127) Prepared batch 2 of 1775178 reads. 9:18:37.348 29G / 34G INFO General (hammer_tools.cpp : 132) Processed batch 2 9:18:38.886 29G / 34G INFO General (hammer_tools.cpp : 136) Written batch 2 9:18:40.802 27G / 34G INFO General (hammer_tools.cpp : 274) Correction done. Changed 13830981 bases in 12424142 reads. 9:18:40.802 27G / 34G INFO General (hammer_tools.cpp : 275) Failed to correct 940 bases out of 40597341152. 9:18:43.576 128M / 34G INFO General (main.cpp : 255) Saving corrected dataset description to /DATA/markop/Pcitri_rnaspades/output/corrected/corrected.yaml 9:18:43.577 128M / 34G INFO General (main.cpp : 262) All done. Exiting. == Dataset description file was created: /DATA/markop/Pcitri_rnaspades/output/corrected/corrected.yaml ===== Read error correction finished. ===== Assembling started. == Running assembler: K49 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades/output/K49/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades/output/K49/configs/mda_mode.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades/output/K49/configs/rna_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from refs/heads/spades_3.13.0, git revision 8ea46659e9b2aca35444a808db550ac333006f8b 0:00:00.000 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.000 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/DATA/markop/Pcitri_rnaspades/output/dataset.info) with K=49 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.000 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 77) Converting reads to binary format for library #0 (takes a while) 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 78) Converting paired reads 0:00:00.195 80M / 80M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:00:00.332 96M / 96M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:00:00.605 128M / 128M INFO General (binary_converter.hpp : 93) 65536 reads processed 0:00:01.149 184M / 184M INFO General (binary_converter.hpp : 93) 131072 reads processed 0:00:02.241 304M / 304M INFO General (binary_converter.hpp : 93) 262144 reads processed 0:00:04.426 540M / 540M INFO General (binary_converter.hpp : 93) 524288 reads processed 0:00:11.678 912M / 912M INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:00:23.015 916M / 916M INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:00:46.205 920M / 920M INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:01:40.689 944M / 944M INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:03:27.141 952M / 952M INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:06:53.513 964M / 968M INFO General (binary_converter.hpp : 117) 32477062 reads written 0:06:54.716 8M / 968M INFO General (read_converter.hpp : 87) Converting single reads 0:06:54.904 140M / 968M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:06:54.975 144M / 968M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:06:55.098 156M / 968M INFO General (binary_converter.hpp : 93) 65536 reads processed 0:06:55.329 184M / 968M INFO General (binary_converter.hpp : 93) 131072 reads processed 0:06:55.854 232M / 968M INFO General (binary_converter.hpp : 93) 262144 reads processed 0:06:56.863 332M / 968M INFO General (binary_converter.hpp : 93) 524288 reads processed 0:06:58.804 536M / 968M INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:07:02.689 940M / 968M INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:07:10.448 1G / 1G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:07:33.324 1G / 1G INFO General (binary_converter.hpp : 117) 7738345 reads written 0:07:35.217 4M / 1G INFO General (read_converter.hpp : 95) Converting merged reads 0:07:35.323 132M / 1G INFO General (binary_converter.hpp : 117) 0 reads written 0:07:35.332 4M / 1G INFO General (read_converter.hpp : 77) Converting reads to binary format for library #1 (takes a while) 0:07:35.332 4M / 1G INFO General (read_converter.hpp : 78) Converting paired reads 0:07:35.542 84M / 1G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:07:35.692 96M / 1G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:07:35.980 128M / 1G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:07:36.578 188M / 1G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:07:37.883 304M / 1G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:07:40.292 540M / 1G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:07:48.365 908M / 1G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:08:00.751 912M / 1G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:08:25.970 920M / 1G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:09:18.333 944M / 1G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:11:04.981 952M / 1G INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:13:45.510 428M / 1G INFO General (binary_converter.hpp : 117) 29915487 reads written 0:13:45.777 8M / 1G INFO General (read_converter.hpp : 87) Converting single reads 0:13:45.925 140M / 1G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:13:45.984 144M / 1G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:13:46.128 160M / 1G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:13:46.356 184M / 1G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:13:46.804 236M / 1G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:13:47.691 336M / 1G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:13:49.490 536M / 1G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:13:53.041 936M / 1G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:14:00.222 1G / 1G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:14:12.194 620M / 1G INFO General (binary_converter.hpp : 117) 5420373 reads written 0:14:12.873 8M / 1G INFO General (read_converter.hpp : 95) Converting merged reads 0:14:12.981 136M / 1G INFO General (binary_converter.hpp : 117) 0 reads written 0:14:12.990 8M / 1G INFO General (read_converter.hpp : 77) Converting reads to binary format for library #2 (takes a while) 0:14:12.990 8M / 1G INFO General (read_converter.hpp : 78) Converting paired reads 0:14:13.175 84M / 1G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:14:13.313 100M / 1G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:14:13.592 128M / 1G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:14:14.134 188M / 1G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:14:15.221 304M / 1G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:14:17.391 540M / 1G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:14:25.638 912M / 1G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:14:36.908 916M / 1G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:14:59.707 920M / 1G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:15:49.185 928M / 1G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:17:26.638 956M / 1G INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:20:46.160 972M / 1G INFO General (binary_converter.hpp : 93) 33554432 reads processed 0:21:10.548 476M / 1G INFO General (binary_converter.hpp : 117) 35525456 reads written 0:21:10.842 8M / 1G INFO General (read_converter.hpp : 87) Converting single reads 0:21:10.992 140M / 1G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:21:11.052 148M / 1G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:21:11.170 160M / 1G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:21:11.407 184M / 1G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:21:11.861 236M / 1G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:21:12.753 336M / 1G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:21:14.553 540M / 1G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:21:18.134 940M / 1G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:21:25.281 1G / 1G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:21:39.725 864M / 1G INFO General (binary_converter.hpp : 117) 6041970 reads written 0:21:40.735 8M / 1G INFO General (read_converter.hpp : 95) Converting merged reads 0:21:40.840 136M / 1G INFO General (binary_converter.hpp : 117) 0 reads written 0:21:40.849 8M / 1G INFO General (read_converter.hpp : 77) Converting reads to binary format for library #3 (takes a while) 0:21:40.849 8M / 1G INFO General (read_converter.hpp : 78) Converting paired reads 0:21:41.034 84M / 1G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:21:41.173 100M / 1G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:21:41.449 128M / 1G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:21:41.996 188M / 1G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:21:43.092 308M / 1G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:21:45.272 544M / 1G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:21:52.479 912M / 1G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:22:03.784 916M / 1G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:22:26.689 920M / 1G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:23:16.013 944M / 1G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:24:52.910 956M / 1G INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:28:11.407 976M / 1G INFO General (binary_converter.hpp : 93) 33554432 reads processed 0:28:12.721 96M / 1G INFO General (binary_converter.hpp : 117) 33557381 reads written 0:28:12.739 8M / 1G INFO General (read_converter.hpp : 87) Converting single reads 0:28:12.886 140M / 1G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:28:12.944 148M / 1G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:28:13.060 160M / 1G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:28:13.286 184M / 1G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:28:13.732 236M / 1G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:28:14.637 336M / 1G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:28:16.427 536M / 1G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:28:20.006 940M / 1G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:28:27.244 1G / 1G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:28:51.373 1G / 1G INFO General (binary_converter.hpp : 117) 8238524 reads written 0:28:53.913 8M / 1G INFO General (read_converter.hpp : 95) Converting merged reads 0:28:54.018 136M / 1G INFO General (binary_converter.hpp : 117) 0 reads written 0:28:54.027 8M / 1G INFO General (construction.cpp : 111) Max read length 150 0:28:54.027 8M / 1G INFO General (construction.cpp : 117) Average read length 139.787 0:28:54.027 8M / 1G INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:28:54.027 8M / 1G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 1024 files using 32 threads. This might take a while. 0:28:54.027 8M / 1G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:28:54.027 8M / 1G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60409 Gb 0:28:54.027 8M / 1G INFO General (kmer_splitters.hpp : 97) Using cell size of 32768 0:29:06.765 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 23765085 reads 0:29:19.628 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 42406194 reads 0:29:32.603 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 61238798 reads 0:29:45.447 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 80044925 reads 0:29:58.585 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 98636514 reads 0:30:11.512 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 117293203 reads 0:30:24.844 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 135943423 reads 0:30:38.482 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 158439740 reads 0:30:51.875 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 177263919 reads 0:31:05.042 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 196231603 reads 0:31:18.659 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 215157250 reads 0:31:31.802 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 233889138 reads 0:31:45.366 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 252669744 reads 0:31:58.628 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 271438951 reads 0:34:58.521 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 540018530 reads 0:35:27.542 17G / 18G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:35:28.928 136M / 18G INFO General (kmer_splitters.hpp : 308) Used 580779968 reads 0:35:28.928 136M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:35:42.527 136M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 371021783 kmers in total. 0:35:42.528 136M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:35:48.030 132M / 18G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:35:48.035 132M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:35:48.036 132M / 18G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:35:48.036 132M / 18G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:35:48.036 132M / 18G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60282 Gb 0:35:48.036 132M / 18G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:35:48.729 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 5772115 kmers 0:35:49.581 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 17032273 kmers 0:35:50.296 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 26028324 kmers 0:35:51.028 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 33275806 kmers 0:35:51.865 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 41575747 kmers 0:35:52.614 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 51044348 kmers 0:35:53.522 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 59860282 kmers 0:35:54.332 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 68105181 kmers 0:35:55.187 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 77323348 kmers 0:35:55.997 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 86831935 kmers 0:35:56.904 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 95644877 kmers 0:35:57.656 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 104387724 kmers 0:35:58.500 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 113623676 kmers 0:35:59.337 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 122537344 kmers 0:36:00.126 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 130791182 kmers 0:36:00.934 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 139383956 kmers 0:36:01.798 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 148459681 kmers 0:36:02.638 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 157562007 kmers 0:36:13.400 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 271837716 kmers 0:36:23.146 17G / 18G INFO General (kmer_splitters.hpp : 385) Used 371023121 kmers. 0:36:23.414 132M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:36:31.334 132M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 369258045 kmers in total. 0:36:31.334 132M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:36:36.937 132M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:36:52.047 328M / 18G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:37:56.560 328M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 171233768 bytes occupied (3.70979 bits per kmer). 0:37:56.875 684M / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:38:14.590 684M / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:38:14.594 680M / 18G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:38:14.594 680M / 18G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:38:14.594 680M / 18G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:38:53.907 680M / 18G INFO Early tip clipping (early_simplification.hpp : 184) 76444443 50-mers were removed by early tip clipper 0:38:53.907 680M / 18G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:38:53.908 680M / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:39:16.362 1G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 8629010 sequences extracted 0:39:26.401 1G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:39:33.474 1G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 759 loops collected 0:39:38.077 3G / 18G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:39:38.078 3G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:39:38.078 3G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:39:48.806 3G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 172103876 bytes occupied (3.71092 bits per kmer). 0:39:49.674 4G / 18G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:48:53.271 4G / 18G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:49:08.494 4G / 18G INFO General (construction.cpp : 464) Processed 17259228 edges 0:49:10.256 2G / 18G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:49:26.627 2G / 18G INFO ThresholdFinder (ec_threshold_finder.hpp : 114) Bucket size: 31 0:49:26.632 2G / 18G INFO General (genomic_info_filler.cpp : 98) Average edge coverage: 89.4698 0:49:26.632 2G / 18G INFO General (genomic_info_filler.cpp : 99) Graph threshold: 1233 0:49:26.894 2G / 18G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 89.4698 0:49:26.894 2G / 18G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:49:26.894 2G / 18G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:49:26.900 2G / 18G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:49:26.901 2G / 18G INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:49:26.901 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:49:27.413 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:49:27.414 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Remover of short poly-AT edges 0:49:27.414 2G / 18G INFO General (simplification.cpp : 76) Removing short polyAT 0:49:39.260 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Remover of short poly-AT edges triggered 860 times 0:49:39.261 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Short PolyA/T Edges 0:49:39.857 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Short PolyA/T Edges triggered 0 times 0:49:39.857 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 0:49:41.773 2G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 97992 times 0:49:41.773 2G / 18G INFO General (graph_simplification.hpp : 701) Removing loops and rc loops with erroneous connections 0:50:07.711 2G / 18G INFO ECLoopRemover (erroneous_connection_remov: 440) Loops: accurately removed/deadend removed/other: 47/1267/53 0:50:07.711 2G / 18G INFO ECLoopRemover (erroneous_connection_remov: 441) RC loops: accurately removed/deadend removed/other: 4/45/317 0:50:07.731 2G / 18G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:50:07.731 2G / 18G INFO General (simplification.cpp : 357) Graph simplification started 0:50:07.731 2G / 18G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:50:07.731 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:50:07.731 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:50:09.266 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 62495 times 0:50:09.266 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:50:12.144 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 206755 times 0:50:12.144 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:55:28.339 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1324208 times 0:55:28.339 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:55:29.324 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1228 times 0:55:29.324 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:55:30.630 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 2230 times 0:55:30.630 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:55:30.821 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 188 times 0:55:30.821 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:55:30.823 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2 times 0:55:30.823 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:55:30.824 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:56:24.324 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 926302 times 0:56:24.324 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:56:24.324 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:56:25.574 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 25592 times 0:56:25.574 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:56:26.188 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 9135 times 0:56:26.189 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:57:53.476 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 173271 times 0:57:53.476 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:57:53.654 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 20 times 0:57:53.654 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:57:53.769 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:57:53.769 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:57:53.770 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:57:56.055 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 44566 times 0:57:56.055 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:57:56.055 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:57:56.570 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 7026 times 0:57:56.570 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:57:56.827 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 141 times 0:57:56.828 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:02.390 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 12884 times 0:58:02.390 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:02.410 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:02.410 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:02.425 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:02.425 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:02.425 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:02.425 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:03.267 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 13881 times 0:58:03.267 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:58:03.267 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:03.581 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1829 times 0:58:03.582 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:03.791 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 15 times 0:58:03.792 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:05.774 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 4002 times 0:58:05.774 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:05.781 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:05.781 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:05.785 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:05.785 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:05.785 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:05.785 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:06.299 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 6701 times 0:58:06.299 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:58:06.299 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:06.594 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 694 times 0:58:06.594 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:06.791 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1 times 0:58:06.791 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:08.002 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1647 times 0:58:08.002 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:08.005 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:08.005 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:08.007 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:08.007 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:08.007 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:08.007 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:08.396 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 4133 times 0:58:08.396 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:58:08.396 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:08.607 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 320 times 0:58:08.607 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:08.787 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:08.788 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:09.893 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 904 times 0:58:09.893 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:09.895 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:09.895 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:09.896 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:09.896 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:09.896 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:09.896 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:10.228 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2874 times 0:58:10.228 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:58:10.228 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:10.443 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 201 times 0:58:10.443 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:10.647 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:10.648 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:11.487 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 580 times 0:58:11.487 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:11.488 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:11.488 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:11.489 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:11.489 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:11.489 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:11.489 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:11.772 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2154 times 0:58:11.772 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:58:11.772 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:11.977 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 135 times 0:58:11.978 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:12.169 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:12.169 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:13.032 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 387 times 0:58:13.032 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:13.033 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:13.033 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:13.034 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:13.034 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:13.034 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:13.034 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:13.297 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1707 times 0:58:13.297 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:58:13.297 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:13.499 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 80 times 0:58:13.500 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:13.692 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:13.693 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:14.480 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 247 times 0:58:14.480 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:14.481 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:14.481 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:14.481 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:14.481 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:14.481 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:14.481 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:14.743 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1413 times 0:58:14.743 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:58:14.743 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:14.928 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 51 times 0:58:14.928 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:15.107 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:15.108 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:15.687 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 183 times 0:58:15.687 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:15.688 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:15.688 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:15.688 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:15.688 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:15.688 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:15.688 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:15.948 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1186 times 0:58:15.948 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:58:15.948 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:16.158 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 48 times 0:58:16.158 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:16.356 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:16.357 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:16.961 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 134 times 0:58:16.961 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:16.962 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:16.962 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:16.962 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:16.962 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:16.962 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:16.962 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:17.164 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:58:17.164 2G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:58:17.165 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:17.165 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:17.165 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:17.165 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:58:17.166 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:17.166 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:17.166 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:17.166 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:58:17.167 2G / 18G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:58:17.167 2G / 18G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:58:17.167 2G / 18G INFO General (graph_simplification.hpp : 453) Disconnection of relatively low covered edges disabled 0:58:17.167 2G / 18G INFO General (graph_simplification.hpp : 489) Complex tip clipping disabled 0:58:17.168 2G / 18G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:58:17.168 2G / 18G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:58:17.168 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:17.425 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 1067 times 0:58:17.426 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:18.815 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 42342 times 0:58:18.815 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:58:29.348 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 2469 times 0:58:29.348 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:29.620 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 39 times 0:58:29.620 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:58:30.348 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 24932 times 0:58:30.348 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:30.905 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 609 times 0:58:30.905 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 0:58:31.412 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 0:58:31.412 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 0:58:31.633 2G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 61 times 0:58:31.634 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:31.934 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 59 times 0:58:31.935 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:32.144 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 183 times 0:58:32.144 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:58:41.830 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 73 times 0:58:41.830 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:42.107 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:42.125 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:58:42.308 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 74 times 0:58:42.308 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:42.877 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 7 times 0:58:42.877 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 0:58:43.369 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 0:58:43.369 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 0:58:43.572 2G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 3 times 0:58:43.573 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:43.579 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 0:58:43.579 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:43.773 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 1 times 0:58:43.773 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:58:53.336 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 0:58:53.338 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:53.339 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:58:53.340 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:58:53.340 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 0:58:53.341 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:58:53.342 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:58:53.342 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 0:58:53.343 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 0:58:53.344 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 0:58:53.344 2G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 0 times 0:58:53.345 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:53.345 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 0:58:53.346 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:58:53.598 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 0:58:53.599 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:59:03.271 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 0:59:03.272 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:59:03.273 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:59:03.274 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:59:03.274 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 0:59:03.275 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:59:03.276 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:59:03.276 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 0:59:03.277 2G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 0:59:03.278 2G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 0:59:03.278 2G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 0 times 0:59:03.279 2G / 18G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:59:05.534 2G / 18G INFO General (simplification.cpp : 470) Counting average coverage 0:59:06.768 2G / 18G INFO General (simplification.cpp : 476) Average coverage = 156.142 0:59:06.768 2G / 18G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:59:06.774 2G / 18G INFO General (contig_output_stage.cpp : 40) Writing GFA to /DATA/markop/Pcitri_rnaspades/output//K49/assembly_graph_with_scaffolds.gfa 0:59:13.097 2G / 18G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K49/before_rr.fasta 0:59:19.453 2G / 18G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /DATA/markop/Pcitri_rnaspades/output//K49/assembly_graph.fastg 0:59:35.509 2G / 18G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K49/simplified_contigs.fasta 0:59:41.771 2G / 18G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K49/final_contigs.fasta 0:59:47.830 2G / 18G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:59:47.830 2G / 18G INFO General (contig_output_stage.cpp : 40) Writing GFA to /DATA/markop/Pcitri_rnaspades/output//K49/assembly_graph_with_scaffolds.gfa 0:59:54.129 2G / 18G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K49/before_rr.fasta 1:00:01.111 2G / 18G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /DATA/markop/Pcitri_rnaspades/output//K49/assembly_graph.fastg 1:00:20.005 2G / 18G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K49/simplified_contigs.fasta 1:00:26.952 2G / 18G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K49/final_contigs.fasta 1:00:34.052 2G / 18G INFO General (launch.hpp : 149) SPAdes finished 1:00:39.140 128M / 18G INFO General (main.cpp : 109) Assembling time: 1 hours 0 minutes 39 seconds Max read length detected as 150 == Running assembler: K73 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades/output/K73/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades/output/K73/configs/mda_mode.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades/output/K73/configs/rna_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from refs/heads/spades_3.13.0, git revision 8ea46659e9b2aca35444a808db550ac333006f8b 0:00:00.000 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.000 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/DATA/markop/Pcitri_rnaspades/output/dataset.info) with K=73 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.000 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.000 4M / 4M INFO General (launch.hpp : 76) Will need read mapping, kmer mapper will be attached 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.003 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.005 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.008 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.009 8M / 8M INFO General (construction.cpp : 111) Max read length 150 0:00:00.009 8M / 8M INFO General (construction.cpp : 117) Average read length 139.787 0:00:00.009 8M / 8M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.009 8M / 8M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 1024 files using 32 threads. This might take a while. 0:00:00.010 8M / 8M INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:00.010 8M / 8M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60409 Gb 0:00:00.010 8M / 8M INFO General (kmer_splitters.hpp : 97) Using cell size of 21845 0:00:11.678 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 22790545 reads 0:00:21.348 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 39484528 reads 0:00:32.218 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 56341063 reads 0:00:42.918 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 73299496 reads 0:00:53.505 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 90007619 reads 0:01:04.674 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 106659975 reads 0:01:15.443 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 123401982 reads 0:01:26.484 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 140094108 reads 0:01:37.914 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 161310502 reads 0:01:49.627 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 178441619 reads 0:02:00.803 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 195719641 reads 0:02:11.568 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 213050582 reads 0:02:22.840 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 230103347 reads 0:02:55.195 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 285345548 reads 0:05:40.386 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 546537363 reads 0:06:02.968 17G / 18G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:06:37.478 132M / 18G INFO General (kmer_splitters.hpp : 308) Used 580779968 reads 0:06:37.478 132M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:07:25.084 132M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 389470070 kmers in total. 0:07:25.084 132M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:07:50.853 132M / 18G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:07:50.853 132M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:07:50.853 132M / 18G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:07:50.853 132M / 18G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:07:50.853 132M / 18G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60282 Gb 0:07:50.853 132M / 18G INFO General (kmer_splitters.hpp : 97) Using cell size of 43690 0:07:51.433 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 3780469 kmers 0:07:52.029 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 7824906 kmers 0:07:52.498 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 11812036 kmers 0:07:53.003 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 15943897 kmers 0:07:53.578 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 19991581 kmers 0:07:54.057 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 23979959 kmers 0:07:54.509 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 28116182 kmers 0:07:55.115 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 32166461 kmers 0:07:55.604 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 36156878 kmers 0:07:56.120 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 40291239 kmers 0:07:56.678 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 44334467 kmers 0:07:57.209 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 48322589 kmers 0:07:57.734 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 52466558 kmers 0:07:58.296 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 56518617 kmers 0:07:58.813 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 60507504 kmers 0:07:59.290 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 64630113 kmers 0:07:59.865 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 68677669 kmers 0:08:09.841 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 137661818 kmers 0:08:28.851 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 271548858 kmers 0:08:46.135 17G / 18G INFO General (kmer_splitters.hpp : 385) Used 389473142 kmers. 0:08:46.349 132M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:09:08.518 132M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 389582114 kmers in total. 0:09:08.518 132M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:09:17.100 132M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:09:35.738 324M / 18G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:11:06.298 324M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 180658088 bytes occupied (3.70978 bits per kmer). 0:11:06.631 696M / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:11:25.762 696M / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:11:25.780 696M / 18G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:11:25.807 696M / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:11:56.009 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 26023561 sequences extracted 0:12:11.417 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:12:18.944 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 27 loops collected 0:12:34.575 8G / 18G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:12:34.575 8G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:12:34.575 8G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:12:46.414 8G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 180629720 bytes occupied (3.71027 bits per kmer). 0:12:47.321 10G / 18G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:20:01.145 10G / 18G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:20:17.101 10G / 18G INFO General (construction.cpp : 464) Processed 32000000 edges 0:20:25.873 10G / 18G INFO General (construction.cpp : 464) Processed 52047036 edges 0:20:28.039 8G / 18G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:21:19.831 8G / 18G INFO ThresholdFinder (ec_threshold_finder.hpp : 114) Bucket size: 20 0:21:19.834 8G / 18G INFO General (genomic_info_filler.cpp : 98) Average edge coverage: 50.5545 0:21:19.834 8G / 18G INFO General (genomic_info_filler.cpp : 99) Graph threshold: 903 0:21:20.036 8G / 18G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 50.5545 0:21:20.036 8G / 18G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:21:20.036 8G / 18G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:21:20.036 8G / 18G INFO General (graph_pack.hpp : 101) Index refill 0:21:20.036 8G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:21:20.036 8G / 18G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:21:20.036 8G / 18G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:21:20.036 8G / 18G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.51904 Gb 0:21:20.036 8G / 18G INFO General (kmer_splitters.hpp : 97) Using cell size of 43690 0:21:35.792 25G / 26G INFO General (edge_index_builders.hpp : 77) Processed 52047036 edges 0:21:35.793 25G / 26G INFO General (edge_index_builders.hpp : 82) Used 52047036 sequences. 0:21:36.721 8G / 26G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:21:43.835 8G / 26G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 389470070 kmers in total. 0:21:43.835 8G / 26G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:21:52.157 8G / 26G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:22:09.882 8G / 26G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:23:40.222 8G / 26G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 180615990 bytes occupied (3.70998 bits per kmer). 0:23:45.423 17G / 26G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:24:01.420 17G / 26G INFO General (edge_index.hpp : 92) Index refilled 0:24:01.422 17G / 26G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:24:48.214 19G / 26G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:27:03.742 19G / 26G INFO General (gap_closer.cpp : 138) Used 32477062 paired reads 0:27:03.742 19G / 26G INFO General (gap_closer.cpp : 140) Merging paired indices 0:27:14.192 17G / 26G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:29:00.782 17G / 26G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 5811 gaps after checking 52669 candidates 0:29:05.604 17G / 26G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:29:54.687 19G / 26G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:32:10.042 19G / 26G INFO General (gap_closer.cpp : 138) Used 29915487 paired reads 0:32:10.042 19G / 26G INFO General (gap_closer.cpp : 140) Merging paired indices 0:32:20.377 17G / 26G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:34:08.094 17G / 26G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 4812 gaps after checking 42534 candidates 0:34:12.323 17G / 26G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:34:58.108 19G / 26G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:37:33.359 19G / 26G INFO General (gap_closer.cpp : 138) Used 35525456 paired reads 0:37:33.359 19G / 26G INFO General (gap_closer.cpp : 140) Merging paired indices 0:37:42.247 17G / 26G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:39:26.247 17G / 26G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 5119 gaps after checking 41404 candidates 0:39:30.730 17G / 26G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:40:15.987 19G / 26G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:42:37.303 19G / 26G INFO General (gap_closer.cpp : 138) Used 33557381 paired reads 0:42:37.303 19G / 26G INFO General (gap_closer.cpp : 140) Merging paired indices 0:42:46.490 17G / 26G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:44:31.688 17G / 26G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 4802 gaps after checking 48825 candidates 0:44:35.838 17G / 26G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:44:36.726 8G / 26G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:44:36.727 8G / 26G INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:44:36.727 8G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:44:38.641 8G / 26G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:44:38.641 8G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Remover of short poly-AT edges 0:44:38.641 8G / 26G INFO General (simplification.cpp : 76) Removing short polyAT 0:45:22.217 8G / 26G INFO Simplification (parallel_processing.hpp : 167) Remover of short poly-AT edges triggered 860 times 0:45:22.217 8G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Short PolyA/T Edges 0:45:24.784 8G / 26G INFO Simplification (parallel_processing.hpp : 167) Short PolyA/T Edges triggered 0 times 0:45:24.784 8G / 26G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 0:47:19.261 8G / 26G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 7473384 times 0:47:19.262 8G / 26G INFO General (graph_simplification.hpp : 701) Removing loops and rc loops with erroneous connections 0:48:13.521 8G / 26G INFO ECLoopRemover (erroneous_connection_remov: 440) Loops: accurately removed/deadend removed/other: 10/291/11 0:48:13.521 8G / 26G INFO ECLoopRemover (erroneous_connection_remov: 441) RC loops: accurately removed/deadend removed/other: 0/29/111 0:48:14.903 8G / 26G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:48:14.903 8G / 26G INFO General (simplification.cpp : 357) Graph simplification started 0:48:14.903 8G / 26G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:48:14.903 8G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:48:14.903 8G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:49:16.398 8G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3705146 times 0:49:16.398 8G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:49:37.008 8G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1136112 times 0:49:37.008 8G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:57:45.412 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 571348 times 0:57:45.412 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:57:46.808 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1985 times 0:57:46.808 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:57:47.516 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 170 times 0:57:47.516 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:57:47.595 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 92 times 0:57:47.595 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:57:47.596 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:57:47.596 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:57:47.596 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 0:57:47.596 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:57:47.596 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:57:47.596 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:58:11.606 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 344312 times 0:58:11.606 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:58:11.606 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:16.486 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 113252 times 0:58:16.487 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:58:17.251 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 6556 times 0:58:17.251 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:25.722 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 92062 times 1:00:25.722 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:25.853 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 23 times 1:00:25.853 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:25.959 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:25.959 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:00:25.961 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:00:28.081 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 26740 times 1:00:28.081 14G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 1:00:28.081 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:29.528 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 26579 times 1:00:29.528 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:30.104 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 57 times 1:00:30.107 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:39.208 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 6419 times 1:00:39.208 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:39.236 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:00:39.236 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:39.254 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:39.254 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:39.254 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:00:39.254 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:00:40.557 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 8918 times 1:00:40.557 14G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 1:00:40.557 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:41.307 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 8383 times 1:00:41.307 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:41.741 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 5 times 1:00:41.741 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:44.967 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1742 times 1:00:44.967 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:44.975 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:00:44.975 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:44.980 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:44.980 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:44.980 14G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:00:44.980 14G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:00:45.556 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 4785 times 1:00:45.556 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 1:00:45.556 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:46.090 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3203 times 1:00:46.090 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:46.478 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:46.478 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:48.877 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 781 times 1:00:48.877 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:48.881 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:00:48.881 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:48.884 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:48.884 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:48.884 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:00:48.884 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:00:49.749 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3067 times 1:00:49.749 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 1:00:49.749 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:50.208 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1393 times 1:00:50.208 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:50.570 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:50.571 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:52.256 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 419 times 1:00:52.256 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:52.259 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:00:52.259 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:52.260 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:52.260 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:52.260 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:00:52.260 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:00:52.713 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2253 times 1:00:52.713 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 1:00:52.713 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:53.117 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 636 times 1:00:53.117 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:53.455 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:53.456 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:55.019 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 254 times 1:00:55.019 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:55.021 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:00:55.021 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:55.022 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:55.022 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:55.022 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:00:55.022 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:00:55.739 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1677 times 1:00:55.739 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 1:00:55.739 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:56.185 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 337 times 1:00:56.185 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:56.578 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:56.579 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:58.247 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 148 times 1:00:58.247 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:58.248 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:00:58.248 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:58.249 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:58.249 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:00:58.249 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:00:58.249 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:00:58.741 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1302 times 1:00:58.741 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 1:00:58.741 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:00:59.119 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 200 times 1:00:59.119 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:00:59.481 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:00:59.481 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:01:00.459 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 95 times 1:01:00.459 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:01:00.460 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:01:00.460 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:01:00.460 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:01:00.460 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:01:00.460 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:01:00.460 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:01:00.863 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1089 times 1:01:00.863 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 1:01:00.863 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:01:01.245 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 132 times 1:01:01.246 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:01:01.592 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:01:01.592 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:01:02.835 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 82 times 1:01:02.835 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:01:02.835 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:01:02.835 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:01:02.836 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:01:02.836 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:01:02.836 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:01:02.836 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:01:03.385 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 927 times 1:01:03.385 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 1:01:03.385 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:01:03.819 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 87 times 1:01:03.820 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:01:04.202 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:01:04.203 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:01:05.715 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 66 times 1:01:05.715 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:01:05.716 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:01:05.716 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:01:05.716 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:01:05.716 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:01:05.716 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:01:05.716 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 1:01:06.161 13G / 26G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:01:06.161 13G / 26G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 1:01:06.164 13G / 26G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 1:01:06.164 13G / 26G INFO General (graph_pack.hpp : 101) Index refill 1:01:06.164 13G / 26G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 1:01:06.164 13G / 26G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 1:01:06.165 13G / 26G INFO General (file_limit.hpp : 32) Open file limit set to 1088 1:01:06.165 13G / 26G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.4587 Gb 1:01:06.165 13G / 26G INFO General (kmer_splitters.hpp : 97) Using cell size of 43690 1:01:12.329 31G / 31G INFO General (edge_index_builders.hpp : 77) Processed 3693016 edges 1:01:12.329 31G / 31G INFO General (edge_index_builders.hpp : 82) Used 3693016 sequences. 1:01:12.944 13G / 31G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 1:01:17.165 13G / 31G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 188469688 kmers in total. 1:01:17.166 13G / 31G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 1:01:21.171 13G / 31G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 1:01:29.126 14G / 31G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 1:02:09.428 14G / 31G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 87401752 bytes occupied (3.70995 bits per kmer). 1:02:13.233 18G / 31G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 1:02:19.094 18G / 31G INFO General (edge_index.hpp : 92) Index refilled 1:02:19.096 18G / 31G INFO General (gap_closer.cpp : 159) Preparing shift maps 1:02:26.971 18G / 31G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 1:03:24.874 18G / 31G INFO General (gap_closer.cpp : 138) Used 32477062 paired reads 1:03:24.875 18G / 31G INFO General (gap_closer.cpp : 140) Merging paired indices 1:03:27.305 18G / 31G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 1:03:35.244 18G / 31G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 820 gaps after checking 34455 candidates 1:03:37.324 18G / 31G INFO General (gap_closer.cpp : 159) Preparing shift maps 1:03:45.680 18G / 31G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 1:04:38.761 18G / 31G INFO General (gap_closer.cpp : 138) Used 29915487 paired reads 1:04:38.761 18G / 31G INFO General (gap_closer.cpp : 140) Merging paired indices 1:04:40.816 18G / 31G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 1:04:48.319 18G / 31G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 432 gaps after checking 31610 candidates 1:04:49.680 18G / 31G INFO General (gap_closer.cpp : 159) Preparing shift maps 1:04:56.022 18G / 31G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 1:05:56.527 18G / 31G INFO General (gap_closer.cpp : 138) Used 35525456 paired reads 1:05:56.527 18G / 31G INFO General (gap_closer.cpp : 140) Merging paired indices 1:05:58.565 18G / 31G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 1:06:06.283 18G / 31G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 540 gaps after checking 36218 candidates 1:06:07.956 18G / 31G INFO General (gap_closer.cpp : 159) Preparing shift maps 1:06:15.868 18G / 31G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 1:07:12.672 18G / 31G INFO General (gap_closer.cpp : 138) Used 33557381 paired reads 1:07:12.672 18G / 31G INFO General (gap_closer.cpp : 140) Merging paired indices 1:07:14.950 18G / 31G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 1:07:23.379 18G / 31G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 443 gaps after checking 37602 candidates 1:07:24.684 18G / 31G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 1:07:24.684 18G / 31G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 1:07:24.684 18G / 31G INFO General (graph_simplification.hpp : 453) Disconnection of relatively low covered edges disabled 1:07:24.684 18G / 31G INFO General (graph_simplification.hpp : 489) Complex tip clipping disabled 1:07:24.684 18G / 31G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 1:07:24.684 18G / 31G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 1:07:24.684 18G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:07:25.450 18G / 31G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 567 times 1:07:25.450 18G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:08:49.541 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 214530 times 1:08:49.541 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 1:09:12.276 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 1903 times 1:09:12.276 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:09:13.096 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 183 times 1:09:13.096 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 1:10:03.355 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 46007 times 1:10:03.355 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:10:08.269 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1034 times 1:10:08.269 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 1:10:08.782 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 1:10:08.782 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:10:09.124 17G / 31G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 141 times 1:10:09.124 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:10:09.504 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 23 times 1:10:09.504 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:10:10.019 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 119 times 1:10:10.019 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 1:10:24.506 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 62 times 1:10:24.506 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:10:25.202 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 1:10:25.203 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 1:10:25.671 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 82 times 1:10:25.671 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:10:26.309 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 7 times 1:10:26.309 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 1:10:26.821 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 1:10:26.821 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:10:27.188 17G / 31G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 1 times 1:10:27.188 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:10:27.189 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 1:10:27.190 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:10:27.500 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 1:10:27.501 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 1:10:41.185 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 1:10:41.186 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:10:41.186 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:10:41.187 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 1:10:41.187 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 1:10:41.187 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:10:41.187 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:10:41.187 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 1:10:41.188 17G / 31G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 1:10:41.188 17G / 31G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:10:41.188 17G / 31G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 0 times 1:10:41.188 17G / 31G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 1:10:44.434 17G / 31G INFO General (simplification.cpp : 470) Counting average coverage 1:10:46.036 17G / 31G INFO General (simplification.cpp : 476) Average coverage = 110.896 1:10:46.036 17G / 31G INFO StageManager (stage.cpp : 132) STAGE == Mismatch Correction 1:10:46.036 17G / 31G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 100137210 kmers to process 1:12:25.044 17G / 31G INFO General (graph_pack.hpp : 111) Normalizing done 1:29:19.714 50G / 50G INFO General (mismatch_shall_not_pass.hp: 189) Finished collecting potential mismatches positions 1:31:24.756 18G / 50G INFO General (mismatch_shall_not_pass.hp: 290) All edges processed 1:31:27.144 17G / 50G INFO General (mismatch_correction.cpp : 27) Corrected 3309 nucleotides 1:31:27.160 17G / 50G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 1:31:27.160 17G / 50G INFO General (contig_output_stage.cpp : 40) Writing GFA to /DATA/markop/Pcitri_rnaspades/output//K73/assembly_graph_with_scaffolds.gfa 1:31:36.725 17G / 50G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K73/before_rr.fasta 1:31:44.110 17G / 50G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /DATA/markop/Pcitri_rnaspades/output//K73/assembly_graph.fastg 1:32:04.672 17G / 50G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K73/simplified_contigs.fasta 1:32:13.242 17G / 50G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K73/intermediate_contigs.fasta 1:32:22.742 17G / 50G INFO StageManager (stage.cpp : 132) STAGE == Paired Information Counting 1:33:03.169 19G / 50G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 100401408 kmers to process 1:34:36.423 19G / 50G INFO General (graph_pack.hpp : 111) Normalizing done 1:34:38.665 19G / 50G INFO General (pair_info_count.cpp : 320) Min edge length for estimation: 245 1:34:38.665 19G / 50G INFO General (pair_info_count.cpp : 331) Estimating insert size for library #0 1:34:38.665 19G / 50G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 1:34:39.002 19G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:34:47.655 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:34:47.737 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:34:47.794 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:34:47.847 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:34:47.913 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:34:47.966 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:34:48.307 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:34:49.021 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:34:57.745 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:35:09.922 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:35:30.937 19G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 32477062 reads processed 1:35:32.533 19G / 50G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 1:35:32.533 19G / 50G INFO General (pair_info_count.cpp : 213) 15067025 paired reads (46.3928% of all) aligned to long edges 1:35:32.572 19G / 50G INFO General (pair_info_count.cpp : 354) Insert size = 234.073, deviation = 84.343, left quantile = 151, right quantile = 349, read length = 150 1:35:32.572 19G / 50G INFO General (pair_info_count.cpp : 383) Mapping library #0 1:35:32.572 19G / 50G INFO General (pair_info_count.cpp : 385) Mapping paired reads (takes a while) 1:35:32.572 19G / 50G INFO General (pair_info_count.cpp : 289) Left insert size quantile 151, right insert size quantile 349, filtering threshold 0, rounding threshold 0 1:35:32.581 19G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:35:49.374 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:35:49.397 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:35:49.473 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:35:49.515 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:35:49.530 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:35:49.538 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:35:49.560 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:35:49.748 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:36:06.377 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:36:23.973 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:37:00.645 19G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 32477062 reads processed 1:37:00.928 19G / 50G INFO General (pair_info_count.cpp : 392) Mapping single reads of library #0 1:37:00.929 19G / 50G INFO General (pair_info_count.cpp : 255) Will calculate lib coverage as well 1:37:00.929 19G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:37:04.928 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:37:04.966 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:37:05.014 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:37:05.044 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:37:05.077 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:37:05.105 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:37:05.295 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:37:05.754 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:37:09.706 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:37:15.043 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:37:28.685 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 1:37:53.806 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 1:37:56.502 19G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 72692469 reads processed 1:37:56.809 19G / 50G INFO General (pair_info_count.cpp : 394) Total paths obtained from single reads: 0 1:37:56.809 19G / 50G INFO General (pair_info_count.cpp : 331) Estimating insert size for library #1 1:37:56.809 19G / 50G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 1:37:57.162 20G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:38:06.015 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:38:06.099 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:38:06.148 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:38:06.210 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:38:06.272 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:38:06.332 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:38:06.496 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:38:07.011 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:38:15.625 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:38:25.895 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:38:43.187 20G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 29915487 reads processed 1:38:44.901 20G / 50G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 1:38:44.901 20G / 50G INFO General (pair_info_count.cpp : 213) 13678615 paired reads (45.7242% of all) aligned to long edges 1:38:44.937 19G / 50G INFO General (pair_info_count.cpp : 354) Insert size = 244.659, deviation = 87.9879, left quantile = 155, right quantile = 366, read length = 150 1:38:44.937 19G / 50G INFO General (pair_info_count.cpp : 383) Mapping library #1 1:38:44.937 19G / 50G INFO General (pair_info_count.cpp : 385) Mapping paired reads (takes a while) 1:38:44.937 19G / 50G INFO General (pair_info_count.cpp : 289) Left insert size quantile 155, right insert size quantile 366, filtering threshold 0, rounding threshold 0 1:38:44.950 19G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:39:01.311 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:39:01.318 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:39:01.357 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:39:01.364 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:39:01.380 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:39:01.413 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:39:01.491 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:39:01.563 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:39:17.802 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:39:34.822 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:40:03.918 19G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 29915487 reads processed 1:40:04.185 19G / 50G INFO General (pair_info_count.cpp : 392) Mapping single reads of library #1 1:40:04.185 19G / 50G INFO General (pair_info_count.cpp : 255) Will calculate lib coverage as well 1:40:04.185 19G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:40:08.412 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:40:08.458 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:40:08.496 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:40:08.528 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:40:08.573 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:40:08.612 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:40:08.819 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:40:09.333 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:40:13.596 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:40:19.064 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:40:33.177 19G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 1:40:55.612 19G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 65251347 reads processed 1:40:55.769 19G / 50G INFO General (pair_info_count.cpp : 394) Total paths obtained from single reads: 0 1:40:55.769 19G / 50G INFO General (pair_info_count.cpp : 331) Estimating insert size for library #2 1:40:55.769 19G / 50G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 1:40:56.160 20G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:41:04.787 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:41:04.864 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:41:04.909 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:41:04.976 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:41:05.010 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:41:05.043 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:41:05.284 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:41:05.848 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:41:13.952 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:41:23.508 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:41:48.036 20G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 35525456 reads processed 1:41:49.709 20G / 50G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 1:41:49.709 20G / 50G INFO General (pair_info_count.cpp : 213) 16103601 paired reads (45.3298% of all) aligned to long edges 1:41:49.757 19G / 50G INFO General (pair_info_count.cpp : 354) Insert size = 244.36, deviation = 86.3308, left quantile = 156, right quantile = 362, read length = 150 1:41:49.757 19G / 50G INFO General (pair_info_count.cpp : 383) Mapping library #2 1:41:49.757 19G / 50G INFO General (pair_info_count.cpp : 385) Mapping paired reads (takes a while) 1:41:49.757 19G / 50G INFO General (pair_info_count.cpp : 289) Left insert size quantile 156, right insert size quantile 362, filtering threshold 0, rounding threshold 0 1:41:49.766 19G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:42:03.145 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:42:03.232 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:42:03.233 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:42:03.244 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:42:03.246 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:42:03.247 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:42:03.318 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:42:03.418 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:42:16.882 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:42:30.769 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:43:06.847 20G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 35525456 reads processed 1:43:07.107 20G / 50G INFO General (pair_info_count.cpp : 392) Mapping single reads of library #2 1:43:07.107 20G / 50G INFO General (pair_info_count.cpp : 255) Will calculate lib coverage as well 1:43:07.107 20G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:43:11.188 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:43:11.234 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:43:11.271 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:43:11.307 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:43:11.340 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:43:11.374 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:43:11.577 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:43:12.032 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:43:16.108 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:43:21.488 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:43:35.187 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 1:44:00.168 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 1:44:05.903 20G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 77092882 reads processed 1:44:06.051 20G / 50G INFO General (pair_info_count.cpp : 394) Total paths obtained from single reads: 0 1:44:06.051 20G / 50G INFO General (pair_info_count.cpp : 331) Estimating insert size for library #3 1:44:06.051 20G / 50G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 1:44:06.434 20G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:44:14.869 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:44:14.937 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:44:15.000 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:44:15.067 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:44:15.107 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:44:15.143 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:44:15.398 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:44:15.931 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:44:24.054 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:44:33.563 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:44:55.571 20G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 33557381 reads processed 1:44:57.181 20G / 50G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 1:44:57.181 20G / 50G INFO General (pair_info_count.cpp : 213) 16061662 paired reads (47.8633% of all) aligned to long edges 1:44:57.220 20G / 50G INFO General (pair_info_count.cpp : 354) Insert size = 234.484, deviation = 85.8385, left quantile = 151, right quantile = 353, read length = 150 1:44:57.220 20G / 50G INFO General (pair_info_count.cpp : 383) Mapping library #3 1:44:57.220 20G / 50G INFO General (pair_info_count.cpp : 385) Mapping paired reads (takes a while) 1:44:57.220 20G / 50G INFO General (pair_info_count.cpp : 289) Left insert size quantile 151, right insert size quantile 353, filtering threshold 0, rounding threshold 0 1:44:57.229 20G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:45:09.883 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:45:09.893 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:45:09.927 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:45:09.945 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:45:09.957 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:45:09.964 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:45:09.989 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:45:10.336 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:45:22.835 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:45:36.785 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:46:07.063 20G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 33557381 reads processed 1:46:07.283 20G / 50G INFO General (pair_info_count.cpp : 392) Mapping single reads of library #3 1:46:07.283 20G / 50G INFO General (pair_info_count.cpp : 255) Will calculate lib coverage as well 1:46:07.283 20G / 50G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 1:46:11.161 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 1:46:11.208 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 1:46:11.245 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 1:46:11.276 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 1:46:11.307 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 1:46:11.354 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 1:46:11.537 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 1:46:11.967 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 1:46:15.779 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 1:46:21.164 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 1:46:34.322 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 1:46:58.916 20G / 50G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 1:47:04.484 20G / 50G INFO General (sequence_mapper_notifier.h: 98) Total 75353286 reads processed 1:47:04.628 20G / 50G INFO General (pair_info_count.cpp : 394) Total paths obtained from single reads: 0 1:47:04.628 20G / 50G INFO StageManager (stage.cpp : 132) STAGE == Distance Estimation 1:47:04.628 20G / 50G INFO General (distance_estimation.cpp : 173) Processing library #0 1:47:04.628 20G / 50G INFO General (distance_estimation.cpp : 149) Weight Filter Done 1:47:04.634 20G / 50G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 1:47:08.630 20G / 50G INFO General (distance_estimation.cpp : 34) Filtering info 1:47:08.630 20G / 50G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 3738844 1:47:12.615 20G / 50G INFO General (pair_info_filters.hpp : 263) Done filtering 1:47:12.621 20G / 50G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 1:47:13.071 20G / 50G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 1:47:13.071 20G / 50G INFO General (distance_estimation.cpp : 160) Improving paired information 1:47:22.238 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 22261; contradictional = 110 1:47:31.808 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 981; contradictional = 0 1:47:31.808 20G / 50G INFO General (distance_estimation.cpp : 173) Processing library #1 1:47:31.808 20G / 50G INFO General (distance_estimation.cpp : 149) Weight Filter Done 1:47:31.808 20G / 50G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 1:47:36.005 20G / 50G INFO General (distance_estimation.cpp : 34) Filtering info 1:47:36.005 20G / 50G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 3823943 1:47:39.939 20G / 50G INFO General (pair_info_filters.hpp : 263) Done filtering 1:47:39.945 20G / 50G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 1:47:40.388 20G / 50G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 1:47:40.388 20G / 50G INFO General (distance_estimation.cpp : 160) Improving paired information 1:47:46.194 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 25364; contradictional = 100 1:47:52.094 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 1191; contradictional = 0 1:47:52.094 20G / 50G INFO General (distance_estimation.cpp : 173) Processing library #2 1:47:52.094 20G / 50G INFO General (distance_estimation.cpp : 149) Weight Filter Done 1:47:52.094 20G / 50G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 1:47:55.894 20G / 50G INFO General (distance_estimation.cpp : 34) Filtering info 1:47:55.894 20G / 50G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 3817751 1:47:59.985 20G / 50G INFO General (pair_info_filters.hpp : 263) Done filtering 1:47:59.992 20G / 50G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 1:48:00.441 20G / 50G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 1:48:00.441 20G / 50G INFO General (distance_estimation.cpp : 160) Improving paired information 1:48:06.595 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 26246; contradictional = 110 1:48:13.239 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 1310; contradictional = 0 1:48:13.239 20G / 50G INFO General (distance_estimation.cpp : 173) Processing library #3 1:48:13.239 20G / 50G INFO General (distance_estimation.cpp : 149) Weight Filter Done 1:48:13.239 20G / 50G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 1:48:16.955 20G / 50G INFO General (distance_estimation.cpp : 34) Filtering info 1:48:16.955 20G / 50G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 3756623 1:48:21.026 20G / 50G INFO General (pair_info_filters.hpp : 263) Done filtering 1:48:21.032 20G / 50G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 1:48:21.462 20G / 50G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 1:48:21.463 20G / 50G INFO General (distance_estimation.cpp : 160) Improving paired information 1:48:28.365 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 24078; contradictional = 100 1:48:34.344 20G / 50G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 1348; contradictional = 0 1:48:34.344 20G / 50G INFO StageManager (stage.cpp : 132) STAGE == Repeat Resolving 1:48:34.345 20G / 50G INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving 1:48:34.345 20G / 50G INFO General (launcher.cpp : 477) ExSPAnder repeat resolving tool started 1:48:45.673 25G / 50G INFO General (launcher.cpp : 392) Creating main extenders, unique edge length = 2000 1:49:02.832 26G / 50G INFO General (extenders_logic.cpp : 472) Using 4 paired-end libraries 1:49:02.832 26G / 50G INFO General (extenders_logic.cpp : 473) Using 4 paired-end scaffolding libraries 1:49:02.832 26G / 50G INFO General (extenders_logic.cpp : 474) Using 0 single read libraries 1:49:02.832 26G / 50G INFO General (launcher.cpp : 420) Total number of extenders is 20 1:49:02.832 26G / 50G INFO General (path_extender.hpp : 885) Processed 0 paths from 1311972 (0%) 1:49:03.090 26G / 50G INFO General (path_extender.hpp : 883) Processed 128 paths from 1311972 (0%) 1:49:03.566 26G / 50G INFO General (path_extender.hpp : 883) Processed 256 paths from 1311972 (0%) 1:49:04.051 26G / 50G INFO General (path_extender.hpp : 883) Processed 512 paths from 1311972 (0%) 1:49:05.214 26G / 50G INFO General (path_extender.hpp : 883) Processed 1024 paths from 1311972 (0%) 1:49:07.173 26G / 50G INFO General (path_extender.hpp : 883) Processed 2048 paths from 1311972 (0%) 1:49:10.979 26G / 50G INFO General (path_extender.hpp : 883) Processed 4096 paths from 1311972 (0%) 1:49:17.768 26G / 50G INFO General (path_extender.hpp : 883) Processed 8192 paths from 1311972 (0%) 1:49:30.159 27G / 50G INFO General (path_extender.hpp : 883) Processed 16384 paths from 1311972 (1%) 1:49:50.024 27G / 50G INFO General (path_extender.hpp : 883) Processed 32768 paths from 1311972 (2%) 1:50:18.353 27G / 50G INFO General (path_extender.hpp : 883) Processed 65536 paths from 1311972 (4%) 1:50:58.941 27G / 50G INFO General (path_extender.hpp : 883) Processed 131072 paths from 1311972 (9%) 1:50:58.988 27G / 50G INFO General (path_extender.hpp : 885) Processed 131198 paths from 1311972 (10%) 1:52:05.682 28G / 50G INFO General (path_extender.hpp : 883) Processed 262144 paths from 1311972 (19%) 1:52:05.749 28G / 50G INFO General (path_extender.hpp : 885) Processed 262396 paths from 1311972 (20%) 1:52:51.452 29G / 50G INFO General (path_extender.hpp : 885) Processed 393594 paths from 1311972 (30%) 1:53:32.150 30G / 50G INFO General (path_extender.hpp : 883) Processed 524288 paths from 1311972 (39%) 1:53:32.301 30G / 50G INFO General (path_extender.hpp : 885) Processed 524792 paths from 1311972 (40%) 1:54:08.773 31G / 50G INFO General (path_extender.hpp : 885) Processed 655990 paths from 1311972 (50%) 1:55:05.534 32G / 50G INFO General (path_extender.hpp : 885) Processed 787188 paths from 1311972 (60%) 1:55:51.712 33G / 50G INFO General (path_extender.hpp : 885) Processed 918386 paths from 1311972 (70%) 1:56:23.794 34G / 50G INFO General (path_extender.hpp : 883) Processed 1048576 paths from 1311972 (79%) 1:56:24.035 34G / 50G INFO General (path_extender.hpp : 885) Processed 1049584 paths from 1311972 (80%) 1:56:54.930 35G / 50G INFO General (path_extender.hpp : 885) Processed 1180782 paths from 1311972 (90%) 1:57:24.675 36G / 50G INFO General (launcher.cpp : 234) Finalizing paths 1:57:24.675 36G / 50G INFO General (launcher.cpp : 236) Deduplicating paths 1:57:31.064 36G / 50G INFO General (launcher.cpp : 240) Paths deduplicated 1:57:31.064 36G / 50G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 1:57:31.064 36G / 50G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 1:57:31.064 36G / 50G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 1:57:34.609 36G / 50G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 1:57:35.085 36G / 50G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 1:57:36.792 36G / 50G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 1:57:41.944 36G / 50G INFO General (launcher.cpp : 257) Paths finalized 1:57:41.944 36G / 50G INFO General (launcher.cpp : 427) Closing gaps in paths 1:57:48.255 36G / 50G INFO General (launcher.cpp : 455) Gap closing completed 1:57:50.968 36G / 50G INFO General (launcher.cpp : 286) Traversing tandem repeats 1:58:04.982 36G / 50G INFO General (launcher.cpp : 296) Traversed 88 loops 1:58:04.982 36G / 50G INFO General (launcher.cpp : 234) Finalizing paths 1:58:04.982 36G / 50G INFO General (launcher.cpp : 236) Deduplicating paths 1:58:06.700 36G / 50G INFO General (launcher.cpp : 240) Paths deduplicated 1:58:06.700 36G / 50G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 1:58:06.700 36G / 50G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 1:58:06.700 36G / 50G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 1:58:09.948 36G / 50G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 1:58:10.106 36G / 50G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 1:58:11.854 36G / 50G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 1:58:16.997 36G / 50G INFO General (launcher.cpp : 257) Paths finalized 1:58:22.225 41G / 50G INFO General (launcher.cpp : 462) Finalizing main paths 1:58:22.225 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 1.3 converted to 122 1:58:22.225 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 110 bp converted to 122 1:58:22.225 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 122 1:58:23.432 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 1.6 converted to 167 1:58:23.432 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 140 bp converted to 167 1:58:23.432 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 167 1:58:23.694 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 1.5 converted to 152 1:58:23.694 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 130 bp converted to 152 1:58:23.694 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 152 1:58:24.253 41G / 50G INFO General (launcher.cpp : 467) Finalizing paths - hard 1:58:26.671 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 1.5 converted to 152 1:58:26.671 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 130 bp converted to 152 1:58:26.671 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 152 1:58:27.816 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 2 converted to 227 1:58:27.817 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 180 bp converted to 227 1:58:27.817 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 227 1:58:27.991 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 2 converted to 227 1:58:27.991 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 180 bp converted to 227 1:58:27.991 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 227 1:58:33.160 41G / 50G INFO General (launcher.cpp : 467) Finalizing paths - soft 1:58:36.106 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 1.05 converted to 84 1:58:36.106 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 85 bp converted to 84 1:58:36.106 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 84 1:58:36.833 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 1.5 converted to 152 1:58:36.833 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 130 bp converted to 152 1:58:36.833 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 152 1:58:36.980 41G / 50G INFO General (launcher.cpp : 279) Read length relative cutoff 1.2 converted to 107 1:58:36.980 41G / 50G INFO General (launcher.cpp : 280) Read length absolute cutoff 100 bp converted to 107 1:58:36.981 41G / 50G INFO General (launcher.cpp : 281) Length cutoff: 107 1:58:46.265 36G / 50G INFO General (launcher.cpp : 529) ExSPAnder repeat resolving tool finished 1:58:59.771 22G / 50G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 1:58:59.771 22G / 50G INFO General (contig_output_stage.cpp : 40) Writing GFA to /DATA/markop/Pcitri_rnaspades/output//K73/assembly_graph_with_scaffolds.gfa 1:59:07.560 22G / 50G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades/output//K73/before_rr.fasta 1:59:18.391 22G / 50G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /DATA/markop/Pcitri_rnaspades/output//K73/assembly_graph.fastg 1:59:42.551 22G / 50G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /DATA/markop/Pcitri_rnaspades/output//K73/transcripts.paths 1:59:50.844 22G / 50G INFO General (launch.hpp : 149) SPAdes finished 2:01:18.169 148M / 50G INFO General (main.cpp : 109) Assembling time: 2 hours 1 minutes 18 seconds ===== Assembling finished. Used k-mer sizes: 49, 73 * Corrected reads are in /DATA/markop/Pcitri_rnaspades/output/corrected/ * Assembled transcripts are in /DATA/markop/Pcitri_rnaspades/output/transcripts.fasta * Paths in the assembly graph corresponding to the transcripts are in /DATA/markop/Pcitri_rnaspades/output/transcripts.paths * Hard filtered transcripts are in /DATA/markop/Pcitri_rnaspades/output/hard_filtered_transcripts.fasta * Soft filtered transcripts are in /DATA/markop/Pcitri_rnaspades/output/soft_filtered_transcripts.fasta ======= SPAdes pipeline finished. SPAdes log can be found here: /DATA/markop/Pcitri_rnaspades/output/spades.log Thank you for using SPAdes!