Command line: /Users/Joey/opt/bin/spades.py -1 /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq -2 /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq -s /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq --careful -t 10 -o /Volumes/Sequencing/Genomes/assembly/03-Spades -m 250 System information: SPAdes version: 3.6.2 Python version: 2.7.5 OS: Darwin-13.4.0-x86_64-i386-64bit Output dir: /Volumes/Sequencing/Genomes/assembly/03-Spades Mode: read error correction and assembling Debug mode is turned OFF Dataset parameters: Multi-cell mode (you should set '--sc' flag if input data was obtained with MDA (single-cell) technology Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq'] right reads: ['/Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq'] interlaced reads: not specified single reads: ['/Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq'] Read error correction parameters: Iterations: 1 PHRED offset will be auto-detected Corrected reads will be compressed (with gzip) Assembly parameters: k: automatic selection based on read length Mismatch careful mode is turned ON Repeat resolution is enabled MismatchCorrector will be used Coverage cutoff is turned OFF Other parameters: Dir for temp files: /Volumes/Sequencing/Genomes/assembly/03-Spades/tmp Threads: 10 Memory limit (in Gb): 250 ======= SPAdes pipeline started. Log can be found here: /Volumes/Sequencing/Genomes/assembly/03-Spades/spades.log ===== Read error correction started. == Running read error correction tool: /Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/hammer /Volumes/Sequencing/Genomes/assembly/03-Spades/corrected/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 83) Starting BayesHammer, built from N/A, git revision N/A 0:00:00.001 4M / 4M INFO General (main.cpp : 84) Loading config from /Volumes/Sequencing/Genomes/assembly/03-Spades/corrected/configs/config.info 0:00:00.006 4M / 4M INFO General (memory_limit.hpp : 43) Memory limit set to 250 Gb 0:00:00.006 4M / 4M INFO General (main.cpp : 93) Trying to determine PHRED offset 0:00:00.021 4M / 4M INFO General (main.cpp : 99) Determined value is 33 0:00:00.021 4M / 4M INFO General (hammer_tools.cpp : 36) Hamming graph threshold tau=1, k=21, subkmer positions = [ 0 10 ] 0:00:00.021 4M / 4M INFO General (main.cpp : 120) Size of aux. kmer data 24 bytes === ITERATION 0 begins === 0:00:00.022 4M / 4M INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:00:00.022 4M / 4M INFO K-mer Splitting (kmer_data.cpp : 141) Splitting kmer instances into 64 buckets. This might take a while. 0:00:00.022 4M / 4M INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:00.022 4M / 4M INFO K-mer Splitting (kmer_data.cpp : 159) Memory available for splitting buffers: 20.833 Gb 0:00:00.022 4M / 4M INFO K-mer Splitting (kmer_data.cpp : 167) Using cell size of 1048576 0:00:00.023 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 181) Processing /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq 0:00:14.081 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 190) Processed 1295687 reads 0:00:25.973 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 190) Processed 2542551 reads 0:00:25.973 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 181) Processing /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq 0:00:38.163 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 190) Processed 3786270 reads 0:00:50.803 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 190) Processed 5033568 reads 0:00:51.352 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 190) Processed 5085102 reads 0:00:51.352 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 181) Processing /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq 0:01:02.731 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 190) Processed 5676597 reads 0:01:02.731 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 195) Processed 5676597 reads 0:01:02.865 16M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:01:13.207 16M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 24230858 kmers in total. 0:01:13.207 16M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:01:19.948 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:01:23.053 16M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:01:24.168 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 7916808 bytes occupied (2.61379 bits per kmer). 0:01:24.307 16M / 3G INFO K-mer Counting (kmer_data.cpp : 280) Arranging kmers in hash map order 0:01:29.104 392M / 3G INFO General (main.cpp : 155) Clustering Hamming graph. 0:01:29.105 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 120) Serializing sub-kmers. 0:01:29.105 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 125) Serializing: [0, 10) 0:01:32.840 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 125) Serializing: [10, 21) 0:01:36.263 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 137) Splitting sub-kmers, pass 1. 0:02:01.314 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 162) Splitting done. Processed 2 blocks. Produced 4676364 blocks. 0:02:01.361 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 171) Merge done, total 149157 new blocks generated. 0:02:01.361 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 176) Spliting sub-kmers, pass 2. 0:02:29.183 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 195) Splitting done. Processed 298314 blocks. Produced 21385452 blocks. 0:02:29.183 392M / 3G INFO Hamming Clustering (hamcluster.cpp : 202) Merge done, saw 8 big blocks out of 21385452 processed. 0:02:44.265 392M / 3G INFO General (main.cpp : 169) Clustering done. Total clusters: 11608196 0:02:44.279 204M / 3G INFO K-mer Counting (kmer_data.cpp : 295) Collecting K-mer information, this takes a while. 0:02:44.536 760M / 3G INFO K-mer Counting (kmer_data.cpp : 301) Processing /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq 0:04:43.335 760M / 3G INFO K-mer Counting (kmer_data.cpp : 301) Processing /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq 0:06:53.563 760M / 3G INFO K-mer Counting (kmer_data.cpp : 301) Processing /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq 0:07:43.359 760M / 3G INFO K-mer Counting (kmer_data.cpp : 308) Collection done, postprocessing. 0:07:43.431 760M / 3G INFO K-mer Counting (kmer_data.cpp : 321) There are 24230858 kmers in total. Among them 21198778 (87.4867%) are singletons. 0:07:43.431 760M / 3G INFO General (main.cpp : 175) Subclustering Hamming graph 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 647) Subclustering done. Total 65 non-read kmers were generated. 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 648) Subclustering statistics: 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 649) Total singleton hamming clusters: 9757543. Among them 3760966 (38.5442%) are good 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 650) Total singleton subclusters: 959. Among them 922 (96.1418%) are good 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 651) Total non-singleton subcluster centers: 1934825. Among them 1880991 (97.2176%) are good 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 652) Average size of non-trivial subcluster: 7.48046 kmers 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 653) Average number of sub-clusters per non-singleton cluster: 1.046 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 654) Total solid k-mers: 5642879 0:08:08.659 760M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 655) Substitution probabilities: [4,4]((0.949992,0.0160258,0.0184972,0.0154849),(0.0163278,0.951995,0.0149416,0.0167356),(0.0164876,0.0148243,0.952211,0.0164768),(0.0153979,0.0184178,0.0159764,0.950208)) 0:08:08.670 760M / 3G INFO General (main.cpp : 180) Finished clustering. 0:08:08.670 760M / 3G INFO General (main.cpp : 199) Starting solid k-mers expansion in 4 threads. 0:09:33.055 760M / 3G INFO General (main.cpp : 220) Solid k-mers iteration 0 produced 263974 new k-mers. 0:10:59.707 760M / 3G INFO General (main.cpp : 220) Solid k-mers iteration 1 produced 27476 new k-mers. 0:12:26.629 760M / 3G INFO General (main.cpp : 220) Solid k-mers iteration 2 produced 663 new k-mers. 0:13:53.305 760M / 3G INFO General (main.cpp : 220) Solid k-mers iteration 3 produced 0 new k-mers. 0:13:53.305 760M / 3G INFO General (main.cpp : 224) Solid k-mers finalized 0:13:53.314 760M / 3G INFO General (hammer_tools.cpp : 210) Starting read correction in 4 threads. 0:13:53.314 760M / 3G INFO General (hammer_tools.cpp : 221) Correcting pair of reads: /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq and /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq 0:13:54.437 1G / 3G INFO General (hammer_tools.cpp : 166) Prepared batch 0 of 400000 reads. 0:14:04.945 1G / 3G INFO General (hammer_tools.cpp : 175) Processed batch 0 0:14:06.907 1G / 3G INFO General (hammer_tools.cpp : 185) Written batch 0 0:14:07.833 1G / 3G INFO General (hammer_tools.cpp : 166) Prepared batch 1 of 400000 reads. 0:14:18.193 1G / 3G INFO General (hammer_tools.cpp : 175) Processed batch 1 0:14:20.431 1G / 3G INFO General (hammer_tools.cpp : 185) Written batch 1 0:14:21.340 1G / 3G INFO General (hammer_tools.cpp : 166) Prepared batch 2 of 400000 reads. 0:14:31.920 1G / 3G INFO General (hammer_tools.cpp : 175) Processed batch 2 0:14:33.994 1G / 3G INFO General (hammer_tools.cpp : 185) Written batch 2 0:14:34.845 1G / 3G INFO General (hammer_tools.cpp : 166) Prepared batch 3 of 400000 reads. 0:14:45.489 1G / 3G INFO General (hammer_tools.cpp : 175) Processed batch 3 0:14:47.701 1G / 3G INFO General (hammer_tools.cpp : 185) Written batch 3 0:14:48.559 1G / 3G INFO General (hammer_tools.cpp : 166) Prepared batch 4 of 400000 reads. 0:14:59.166 1G / 3G INFO General (hammer_tools.cpp : 175) Processed batch 4 0:15:01.529 1G / 3G INFO General (hammer_tools.cpp : 185) Written batch 4 0:15:02.408 1G / 3G INFO General (hammer_tools.cpp : 166) Prepared batch 5 of 400000 reads. 0:15:12.455 1G / 3G INFO General (hammer_tools.cpp : 175) Processed batch 5 0:15:14.281 1G / 3G INFO General (hammer_tools.cpp : 185) Written batch 5 0:15:14.586 1G / 3G INFO General (hammer_tools.cpp : 166) Prepared batch 6 of 142551 reads. 0:15:18.335 1G / 3G INFO General (hammer_tools.cpp : 175) Processed batch 6 0:15:19.175 1G / 3G INFO General (hammer_tools.cpp : 185) Written batch 6 0:15:19.602 760M / 3G INFO General (hammer_tools.cpp : 248) Correcting single reads: /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq 0:15:20.465 956M / 3G INFO General (hammer_tools.cpp : 125) Prepared batch 0 of 400000 reads. 0:15:30.904 956M / 3G INFO General (hammer_tools.cpp : 131) Processed batch 0 0:15:32.092 956M / 3G INFO General (hammer_tools.cpp : 135) Written batch 0 0:15:32.469 1020M / 3G INFO General (hammer_tools.cpp : 125) Prepared batch 1 of 191495 reads. 0:15:37.792 1020M / 3G INFO General (hammer_tools.cpp : 131) Processed batch 1 0:15:38.490 1020M / 3G INFO General (hammer_tools.cpp : 135) Written batch 1 0:15:38.720 760M / 3G INFO General (hammer_tools.cpp : 269) Correction done. Changed 915418 bases in 788080 reads. 0:15:38.720 760M / 3G INFO General (hammer_tools.cpp : 270) Failed to correct 329566 bases out of 599125404. 0:15:38.784 16M / 3G INFO General (main.cpp : 257) Saving corrected dataset description to /Volumes/Sequencing/Genomes/assembly/03-Spades/corrected/corrected.yaml 0:15:38.787 16M / 3G INFO General (main.cpp : 264) All done. Exiting. == Compressing corrected reads (with gzip) == Dataset description file was created: /Volumes/Sequencing/Genomes/assembly/03-Spades/corrected/corrected.yaml ===== Read error correction finished. ===== Assembling started. == Running assembler: K21 0:00:00.000 4M / 4M INFO General (memory_limit.hpp : 43) Memory limit set to 250 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 147) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 148) Assembling dataset (/Volumes/Sequencing/Genomes/assembly/03-Spades/dataset.info) with K=21 0:00:00.000 4M / 4M INFO General (launch.hpp : 30) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 31) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 39) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 126) STAGE == Construction 0:00:00.003 4M / 4M INFO General (read_converter.hpp : 79) Converting reads to binary format (takes a while) 0:00:00.003 4M / 4M INFO General (read_converter.hpp : 81) Paired reads for library #0 0:00:00.254 76M / 84M INFO General (binary_converter.hpp : 139) 16384 reads processed 0:00:00.374 88M / 88M INFO General (binary_converter.hpp : 139) 32768 reads processed 0:00:00.609 108M / 108M INFO General (binary_converter.hpp : 139) 65536 reads processed 0:00:01.086 148M / 148M INFO General (binary_converter.hpp : 139) 131072 reads processed 0:00:02.161 232M / 232M INFO General (binary_converter.hpp : 139) 262144 reads processed 0:00:04.026 400M / 400M INFO General (binary_converter.hpp : 139) 524288 reads processed 0:00:09.079 660M / 660M INFO General (binary_converter.hpp : 139) 1048576 reads processed 0:00:18.188 660M / 660M INFO General (binary_converter.hpp : 139) 2097152 reads processed 0:00:22.551 500M / 660M INFO General (binary_converter.hpp : 159) 2541677 reads written 0:00:23.401 4M / 660M INFO General (read_converter.hpp : 91) Single reads for library #0 0:00:23.751 140M / 660M INFO General (binary_converter.hpp : 139) 16384 reads processed 0:00:23.827 144M / 660M INFO General (binary_converter.hpp : 139) 32768 reads processed 0:00:23.981 160M / 660M INFO General (binary_converter.hpp : 139) 65536 reads processed 0:00:24.299 188M / 660M INFO General (binary_converter.hpp : 139) 131072 reads processed 0:00:24.939 248M / 660M INFO General (binary_converter.hpp : 139) 262144 reads processed 0:00:26.219 368M / 660M INFO General (binary_converter.hpp : 139) 524288 reads processed 0:00:26.902 392M / 660M INFO General (binary_converter.hpp : 159) 584491 reads written 0:00:27.592 4M / 660M INFO General (graph_construction.hpp : 130) Constructing DeBruijn graph for k=21 0:00:27.592 4M / 660M INFO General (kmer_splitters.hpp : 179) Splitting kmer instances into 16 buckets. This might take a while. 0:00:27.592 4M / 660M INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:27.592 4M / 660M INFO General (kmer_splitters.hpp : 197) Memory available for splitting buffers: 20.833 Gb 0:00:27.592 4M / 660M INFO General (kmer_splitters.hpp : 206) Using cell size of 4194304 0:00:45.531 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 6845856 reads 0:00:58.437 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 11335690 reads 0:00:58.437 2G / 2G INFO General (kmer_splitters.hpp : 241) Adding contigs from previous K 0:00:58.437 2G / 2G INFO General (kmer_splitters.hpp : 252) Used 11335690 reads. Maximum read length 190 0:00:58.437 2G / 2G INFO General (kmer_splitters.hpp : 253) Average read length 105.555 0:00:58.607 16M / 2G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:59.035 16M / 2G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 5397963 kmers in total. 0:00:59.035 16M / 2G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:01:00.289 16M / 2G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:01:00.289 16M / 2G INFO General (kmer_splitters.hpp : 386) Splitting kmer instances into 64 buckets. This might take a while. 0:01:00.290 16M / 2G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:01:00.290 16M / 2G INFO General (kmer_splitters.hpp : 404) Memory available for splitting buffers: 20.832 Gb 0:01:00.290 16M / 2G INFO General (kmer_splitters.hpp : 412) Using cell size of 1048576 0:01:02.569 3G / 3G INFO General (kmer_splitters.hpp : 435) Processed 5397963 kmers 0:01:02.569 3G / 3G INFO General (kmer_splitters.hpp : 444) Used 5397963 kmers. 0:01:02.578 16M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:01:02.626 16M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 5407589 kmers in total. 0:01:02.626 16M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:01:05.138 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:01:05.756 16M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:01:05.940 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1766904 bytes occupied (2.61396 bits per kmer). 0:01:05.945 24M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 391) Building k-mer extensions from k+1-mers 0:01:07.633 24M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 395) Building k-mer extensions from k+1-mers finished. 0:01:07.634 24M / 3G INFO Early tip clipping (early_simplification.hpp : 243) Early tip clipping 0:01:14.955 24M / 3G INFO Early tip clipping (early_simplification.hpp : 246) 405722 22-mers were removed by early tip clipper 0:01:14.955 24M / 3G INFO General (graph_construction.hpp : 146) Condensing graph 0:01:14.956 24M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 338) Extracting unbranching paths 0:01:17.992 52M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 352) Extracting unbranching paths finished. 255720 sequences extracted 0:01:19.087 48M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 312) Collecting perfect loops 0:01:20.300 48M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 327) Collecting perfect loops finished. 252 loops collected 0:01:20.510 76M / 3G INFO General (graph_construction.hpp : 151) Building index with from graph 0:01:20.510 76M / 3G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:01:20.510 76M / 3G INFO General (kmer_splitters.hpp : 296) Splitting kmer instances into 16 buckets. This might take a while. 0:01:20.511 76M / 3G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:01:20.511 76M / 3G INFO General (kmer_splitters.hpp : 314) Memory available for splitting buffers: 83.3086 Gb 0:01:20.511 76M / 3G INFO General (kmer_splitters.hpp : 319) Using cell size of 4194304 0:01:21.264 652M / 3G INFO General (kmer_splitters.hpp : 332) Processed 255972 edges 0:01:21.264 652M / 3G INFO General (kmer_splitters.hpp : 337) Used 255972 sequences. 0:01:21.269 76M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:01:21.359 76M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 4992241 kmers in total. 0:01:21.359 76M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:01:22.881 76M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:01:24.007 80M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:01:24.184 80M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1631168 bytes occupied (2.61393 bits per kmer). 0:01:24.241 196M / 3G INFO General (edge_index_builders.hpp : 28) Collecting k-mer coverage information from graph, this takes a while. 0:01:28.303 188M / 3G INFO General (graph_construction.hpp : 183) Filling coverage index 0:01:28.303 188M / 3G INFO General (edge_index_builders.hpp : 106) Collecting k-mer coverage information from reads, this takes a while. 0:02:54.500 188M / 3G INFO General (graph_construction.hpp : 185) Filling coverage and flanking coverage from index 0:02:55.038 188M / 3G INFO General (construction.cpp : 34) Figured out: read length = 190 0:02:55.038 188M / 3G INFO StageManager (stage.cpp : 126) STAGE == EC Threshold Finding 0:02:55.170 188M / 3G INFO General (kmer_coverage_model.cpp : 179) Kmer coverage valley at: 18 0:02:55.170 188M / 3G INFO General (kmer_coverage_model.cpp : 199) K-mer histogram maximum: 432 0:02:55.170 188M / 3G INFO General (kmer_coverage_model.cpp : 235) Estimated median coverage: 452. Coverage mad: 71.1648 0:02:55.171 188M / 3G INFO General (kmer_coverage_model.cpp : 262) Fitting coverage model 0:02:55.587 188M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 2 0:02:56.727 188M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 4 0:03:01.593 188M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 8 0:03:13.267 188M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 16 0:03:17.200 188M / 3G INFO General (kmer_coverage_model.cpp : 310) Fitted mean coverage: 449.933. Fitted coverage std. dev: 73.0461 0:03:17.212 188M / 3G INFO General (kmer_coverage_model.cpp : 335) Probability of erroneous kmer at valley: 0.999799 0:03:17.212 188M / 3G INFO General (kmer_coverage_model.cpp : 359) Preliminary threshold calculated as: 169 0:03:17.212 188M / 3G INFO General (kmer_coverage_model.cpp : 363) Threshold adjusted to: 169 0:03:17.212 188M / 3G INFO General (kmer_coverage_model.cpp : 376) Estimated genome size (ignoring repeats): 934779 0:03:17.212 188M / 3G INFO General (genomic_info_filler.cpp : 105) Mean coverage was calculated as 449.933 0:03:17.213 188M / 3G INFO General (genomic_info_filler.cpp : 119) EC coverage threshold value was calculated as 169 0:03:17.213 188M / 3G INFO General (genomic_info_filler.cpp : 120) Trusted kmer low bound: 0 0:03:17.213 188M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification 0:03:17.235 68M / 3G INFO General (graph_simplification.hpp : 970) Graph simplification started 0:03:17.235 68M / 3G INFO General (graph_simplification.hpp : 975) Fast simplification mode disabled 0:03:17.236 68M / 3G INFO General (graph_simplification.hpp : 695) PROCEDURE == Presimplification 0:03:17.236 68M / 3G INFO General (graph_simplification.hpp : 213) Removing short low covered self-conjugate connections 0:03:17.250 68M / 3G INFO General (graph_simplification.hpp : 699) Further presimplification is disabled 0:03:17.250 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 1 0:03:17.339 76M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:17.545 76M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:18.552 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:19.316 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 2 0:03:19.352 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:19.421 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:19.502 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:19.531 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 3 0:03:19.562 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:19.625 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:19.705 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:19.736 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 4 0:03:19.770 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:19.824 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:19.890 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:19.916 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 5 0:03:19.945 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:20.010 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:20.079 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:20.115 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 6 0:03:20.149 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:20.209 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:20.281 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:20.307 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 7 0:03:20.335 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:20.386 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:20.456 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:20.485 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 8 0:03:20.515 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:20.570 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:20.630 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:20.660 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 9 0:03:20.689 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:20.741 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:20.801 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:20.827 72M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 10 0:03:20.856 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:20.908 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:20.968 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:03:20.993 72M / 3G INFO General (graph_simplification.hpp : 839) PROCEDURE == Post simplification 0:03:20.993 72M / 3G INFO General (graph_simplification.hpp : 856) Iteration 0 0:03:20.993 72M / 3G INFO General (graph_simplification.hpp : 255) Removal of relatively low covered connections disabled 0:03:21.001 72M / 3G INFO General (graph_simplification.hpp : 530) Complex tip clipping disabled 0:03:21.033 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:03:21.095 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:03:21.131 72M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification Cleanup 0:03:21.131 72M / 3G INFO General (graph_simplification.hpp : 406) Removing isolated edges 0:03:21.131 72M / 3G INFO General (graph_simplification.hpp : 407) All edges shorter than 190 will be removed 0:03:21.131 72M / 3G INFO General (graph_simplification.hpp : 408) Also edges shorter than 0 and coverage smaller than 2 will be removed 0:03:21.350 28M / 3G INFO General (simplification.cpp : 88) Counting average coverage 0:03:21.350 28M / 3G INFO General (simplification.cpp : 91) Average coverage = 497.841 0:03:21.350 28M / 3G INFO StageManager (stage.cpp : 126) STAGE == Contig Output 0:03:21.358 28M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K21/simplified_contigs.fasta 0:03:21.397 28M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K21/before_rr.fasta 0:03:21.431 28M / 3G INFO General (contig_output.hpp : 334) Outputting graph to /Volumes/Sequencing/Genomes/assembly/03-Spades//K21/assembly_graph.fastg 0:03:21.501 28M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K21/final_contigs.fasta 0:03:21.551 28M / 3G INFO General (launch.hpp : 112) SPAdes finished 0:03:21.629 16M / 3G INFO General (main.cpp : 168) Assembling time: 0 hours 3 minutes 21 seconds == Warning == Default k-mer sizes were set to [21, 33, 55, 77] because estimated read length (190) is equal to or greater than 150 == Running assembler: K33 0:00:00.000 4M / 4M INFO General (memory_limit.hpp : 43) Memory limit set to 250 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 147) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 148) Assembling dataset (/Volumes/Sequencing/Genomes/assembly/03-Spades/dataset.info) with K=33 0:00:00.000 4M / 4M INFO General (launch.hpp : 30) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 31) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 39) Two-step RR enabled: 0 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 126) STAGE == Construction 0:00:00.000 4M / 4M INFO General (construction.cpp : 45) Contigs from previous K will be used 0:00:00.007 4M / 4M INFO General (read_converter.hpp : 49) Binary reads detected 0:00:00.007 4M / 4M INFO General (graph_construction.hpp : 130) Constructing DeBruijn graph for k=33 0:00:00.008 4M / 4M INFO General (kmer_splitters.hpp : 179) Splitting kmer instances into 16 buckets. This might take a while. 0:00:00.008 4M / 4M INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:00.008 4M / 4M INFO General (kmer_splitters.hpp : 197) Memory available for splitting buffers: 20.833 Gb 0:00:00.008 4M / 4M INFO General (kmer_splitters.hpp : 206) Using cell size of 2097152 0:00:10.199 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 4042288 reads 0:00:19.730 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 8082469 reads 0:00:29.302 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 11199186 reads 0:00:29.901 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 11335690 reads 0:00:29.901 2G / 2G INFO General (kmer_splitters.hpp : 241) Adding contigs from previous K 0:00:30.057 2G / 2G INFO General (kmer_splitters.hpp : 252) Used 11335690 reads. Maximum read length 190 0:00:30.057 2G / 2G INFO General (kmer_splitters.hpp : 253) Average read length 105.555 0:00:30.223 16M / 2G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:31.637 16M / 2G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 5208273 kmers in total. 0:00:31.637 16M / 2G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:34.100 16M / 2G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:00:34.100 16M / 2G INFO General (kmer_splitters.hpp : 386) Splitting kmer instances into 64 buckets. This might take a while. 0:00:34.101 16M / 2G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:34.101 16M / 2G INFO General (kmer_splitters.hpp : 404) Memory available for splitting buffers: 20.832 Gb 0:00:34.101 16M / 2G INFO General (kmer_splitters.hpp : 412) Using cell size of 524288 0:00:36.593 3G / 3G INFO General (kmer_splitters.hpp : 435) Processed 5208273 kmers 0:00:36.593 3G / 3G INFO General (kmer_splitters.hpp : 444) Used 5208273 kmers. 0:00:36.609 16M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:37.362 16M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 5228021 kmers in total. 0:00:37.362 16M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:40.043 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:00:40.634 16M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:00:41.186 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1708224 bytes occupied (2.61395 bits per kmer). 0:00:41.191 24M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 391) Building k-mer extensions from k+1-mers 0:00:42.895 24M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 395) Building k-mer extensions from k+1-mers finished. 0:00:42.895 24M / 3G INFO Early tip clipping (early_simplification.hpp : 243) Early tip clipping 0:00:50.062 24M / 3G INFO Early tip clipping (early_simplification.hpp : 246) 431636 34-mers were removed by early tip clipper 0:00:50.063 24M / 3G INFO General (graph_construction.hpp : 146) Condensing graph 0:00:50.063 24M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 338) Extracting unbranching paths 0:00:53.370 48M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 352) Extracting unbranching paths finished. 224659 sequences extracted 0:00:54.460 48M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 312) Collecting perfect loops 0:00:55.696 48M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 327) Collecting perfect loops finished. 250 loops collected 0:00:55.892 76M / 3G INFO General (graph_construction.hpp : 151) Building index with from graph 0:00:55.893 76M / 3G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:00:55.893 76M / 3G INFO General (kmer_splitters.hpp : 296) Splitting kmer instances into 16 buckets. This might take a while. 0:00:55.893 76M / 3G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:55.893 76M / 3G INFO General (kmer_splitters.hpp : 314) Memory available for splitting buffers: 83.3086 Gb 0:00:55.893 76M / 3G INFO General (kmer_splitters.hpp : 319) Using cell size of 2097152 0:00:56.677 652M / 3G INFO General (kmer_splitters.hpp : 332) Processed 224909 edges 0:00:56.677 652M / 3G INFO General (kmer_splitters.hpp : 337) Used 224909 sequences. 0:00:56.683 76M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:57.200 76M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 4776637 kmers in total. 0:00:57.200 76M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:59.180 76M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:01:00.257 76M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:01:00.774 76M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1560744 bytes occupied (2.61396 bits per kmer). 0:01:00.827 188M / 3G INFO General (edge_index_builders.hpp : 28) Collecting k-mer coverage information from graph, this takes a while. 0:01:04.556 180M / 3G INFO General (graph_construction.hpp : 183) Filling coverage index 0:01:04.556 180M / 3G INFO General (edge_index_builders.hpp : 106) Collecting k-mer coverage information from reads, this takes a while. 0:02:25.794 180M / 3G INFO General (graph_construction.hpp : 185) Filling coverage and flanking coverage from index 0:02:26.360 180M / 3G INFO General (construction.cpp : 34) Figured out: read length = 190 0:02:26.360 180M / 3G INFO StageManager (stage.cpp : 126) STAGE == EC Threshold Finding 0:02:26.455 180M / 3G INFO General (kmer_coverage_model.cpp : 179) Kmer coverage valley at: 17 0:02:26.455 180M / 3G INFO General (kmer_coverage_model.cpp : 199) K-mer histogram maximum: 371 0:02:26.455 180M / 3G INFO General (kmer_coverage_model.cpp : 235) Estimated median coverage: 388. Coverage mad: 62.2692 0:02:26.455 180M / 3G INFO General (kmer_coverage_model.cpp : 262) Fitting coverage model 0:02:26.833 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 2 0:02:27.794 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 4 0:02:31.188 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 8 0:02:43.136 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 16 0:02:53.659 180M / 3G INFO General (kmer_coverage_model.cpp : 310) Fitted mean coverage: 385.58. Fitted coverage std. dev: 63.275 0:02:53.669 180M / 3G INFO General (kmer_coverage_model.cpp : 335) Probability of erroneous kmer at valley: 0.99981 0:02:53.669 180M / 3G INFO General (kmer_coverage_model.cpp : 359) Preliminary threshold calculated as: 155 0:02:53.669 180M / 3G INFO General (kmer_coverage_model.cpp : 363) Threshold adjusted to: 155 0:02:53.669 180M / 3G INFO General (kmer_coverage_model.cpp : 376) Estimated genome size (ignoring repeats): 943021 0:02:53.669 180M / 3G INFO General (genomic_info_filler.cpp : 105) Mean coverage was calculated as 385.58 0:02:53.670 180M / 3G INFO General (genomic_info_filler.cpp : 119) EC coverage threshold value was calculated as 155 0:02:53.670 180M / 3G INFO General (genomic_info_filler.cpp : 120) Trusted kmer low bound: 0 0:02:53.670 180M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification 0:02:53.679 68M / 3G INFO General (graph_simplification.hpp : 970) Graph simplification started 0:02:53.679 68M / 3G INFO General (graph_simplification.hpp : 975) Fast simplification mode disabled 0:02:53.679 68M / 3G INFO General (graph_simplification.hpp : 695) PROCEDURE == Presimplification 0:02:53.679 68M / 3G INFO General (graph_simplification.hpp : 213) Removing short low covered self-conjugate connections 0:02:53.691 68M / 3G INFO General (graph_simplification.hpp : 699) Further presimplification is disabled 0:02:53.691 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 1 0:02:53.760 72M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:53.946 72M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:54.523 72M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:55.106 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 2 0:02:55.139 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:55.199 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:55.281 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:55.310 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 3 0:02:55.343 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:55.407 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:55.469 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:55.498 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 4 0:02:55.529 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:55.584 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:55.647 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:55.675 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 5 0:02:55.706 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:55.760 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:55.823 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:55.851 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 6 0:02:55.881 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:55.949 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:56.019 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:56.053 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 7 0:02:56.089 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:56.166 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:56.244 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:56.273 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 8 0:02:56.304 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:56.358 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:56.436 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:56.466 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 9 0:02:56.497 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:56.553 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:56.618 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:56.645 68M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 10 0:02:56.679 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:56.736 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:56.798 68M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:56.830 68M / 3G INFO General (graph_simplification.hpp : 839) PROCEDURE == Post simplification 0:02:56.830 68M / 3G INFO General (graph_simplification.hpp : 856) Iteration 0 0:02:56.830 68M / 3G INFO General (graph_simplification.hpp : 255) Removal of relatively low covered connections disabled 0:02:56.830 68M / 3G INFO General (graph_simplification.hpp : 530) Complex tip clipping disabled 0:02:56.869 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:56.925 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:56.953 68M / 3G INFO General (graph_simplification.hpp : 856) Iteration 1 0:02:56.953 68M / 3G INFO General (graph_simplification.hpp : 255) Removal of relatively low covered connections disabled 0:02:56.953 68M / 3G INFO General (graph_simplification.hpp : 530) Complex tip clipping disabled 0:02:56.982 68M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:57.037 68M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:57.077 68M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification Cleanup 0:02:57.077 68M / 3G INFO General (graph_simplification.hpp : 406) Removing isolated edges 0:02:57.077 68M / 3G INFO General (graph_simplification.hpp : 407) All edges shorter than 190 will be removed 0:02:57.077 68M / 3G INFO General (graph_simplification.hpp : 408) Also edges shorter than 0 and coverage smaller than 2 will be removed 0:02:57.354 24M / 3G INFO General (simplification.cpp : 88) Counting average coverage 0:02:57.355 24M / 3G INFO General (simplification.cpp : 91) Average coverage = 423.927 0:02:57.355 24M / 3G INFO StageManager (stage.cpp : 126) STAGE == Contig Output 0:02:57.355 24M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K33/simplified_contigs.fasta 0:02:57.407 24M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K33/before_rr.fasta 0:02:57.446 24M / 3G INFO General (contig_output.hpp : 334) Outputting graph to /Volumes/Sequencing/Genomes/assembly/03-Spades//K33/assembly_graph.fastg 0:02:57.509 24M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K33/final_contigs.fasta 0:02:57.540 24M / 3G INFO General (launch.hpp : 112) SPAdes finished 0:02:57.556 16M / 3G INFO General (main.cpp : 168) Assembling time: 0 hours 2 minutes 57 seconds == Running assembler: K55 0:00:00.000 4M / 4M INFO General (memory_limit.hpp : 43) Memory limit set to 250 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 147) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 148) Assembling dataset (/Volumes/Sequencing/Genomes/assembly/03-Spades/dataset.info) with K=55 0:00:00.000 4M / 4M INFO General (launch.hpp : 30) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 31) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 39) Two-step RR enabled: 0 0:00:00.000 4M / 4M INFO General (launch.hpp : 58) Will need read mapping, kmer mapper will be attached 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 126) STAGE == Construction 0:00:00.000 4M / 4M INFO General (construction.cpp : 45) Contigs from previous K will be used 0:00:00.048 4M / 4M INFO General (read_converter.hpp : 49) Binary reads detected 0:00:00.048 4M / 4M INFO General (graph_construction.hpp : 130) Constructing DeBruijn graph for k=55 0:00:00.048 4M / 4M INFO General (kmer_splitters.hpp : 179) Splitting kmer instances into 16 buckets. This might take a while. 0:00:00.048 4M / 4M INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:00.048 4M / 4M INFO General (kmer_splitters.hpp : 197) Memory available for splitting buffers: 20.833 Gb 0:00:00.048 4M / 4M INFO General (kmer_splitters.hpp : 206) Using cell size of 2097152 0:00:10.791 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 6042112 reads 0:00:20.744 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 10986816 reads 0:00:22.019 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 11335690 reads 0:00:22.019 2G / 2G INFO General (kmer_splitters.hpp : 241) Adding contigs from previous K 0:00:22.171 2G / 2G INFO General (kmer_splitters.hpp : 252) Used 11335690 reads. Maximum read length 190 0:00:22.171 2G / 2G INFO General (kmer_splitters.hpp : 253) Average read length 105.555 0:00:22.338 16M / 2G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:23.164 16M / 2G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 4664198 kmers in total. 0:00:23.164 16M / 2G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:25.023 16M / 2G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:00:25.023 16M / 2G INFO General (kmer_splitters.hpp : 386) Splitting kmer instances into 64 buckets. This might take a while. 0:00:25.023 16M / 2G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:25.023 16M / 2G INFO General (kmer_splitters.hpp : 404) Memory available for splitting buffers: 20.832 Gb 0:00:25.023 16M / 2G INFO General (kmer_splitters.hpp : 412) Using cell size of 524288 0:00:27.692 3G / 3G INFO General (kmer_splitters.hpp : 435) Processed 4664198 kmers 0:00:27.692 3G / 3G INFO General (kmer_splitters.hpp : 444) Used 4664198 kmers. 0:00:27.707 16M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:27.915 16M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 4693047 kmers in total. 0:00:27.915 16M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:31.550 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:00:32.062 16M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:00:32.598 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1533472 bytes occupied (2.61403 bits per kmer). 0:00:32.602 24M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 391) Building k-mer extensions from k+1-mers 0:00:34.181 24M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 395) Building k-mer extensions from k+1-mers finished. 0:00:34.181 24M / 3G INFO General (graph_construction.hpp : 146) Condensing graph 0:00:34.181 24M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 338) Extracting unbranching paths 0:00:36.804 52M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 352) Extracting unbranching paths finished. 320982 sequences extracted 0:00:37.802 52M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 312) Collecting perfect loops 0:00:38.822 52M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 327) Collecting perfect loops finished. 28 loops collected 0:00:39.083 100M / 3G INFO General (graph_construction.hpp : 151) Building index with from graph 0:00:39.083 100M / 3G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:00:39.083 100M / 3G INFO General (kmer_splitters.hpp : 296) Splitting kmer instances into 16 buckets. This might take a while. 0:00:39.083 100M / 3G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:39.083 100M / 3G INFO General (kmer_splitters.hpp : 314) Memory available for splitting buffers: 83.3008 Gb 0:00:39.083 100M / 3G INFO General (kmer_splitters.hpp : 319) Using cell size of 2097152 0:00:40.445 676M / 3G INFO General (kmer_splitters.hpp : 332) Processed 321010 edges 0:00:40.445 676M / 3G INFO General (kmer_splitters.hpp : 337) Used 321010 sequences. 0:00:40.450 100M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:40.860 100M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 4664198 kmers in total. 0:00:40.860 100M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:43.270 100M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:00:44.367 100M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:00:44.838 100M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1524016 bytes occupied (2.61398 bits per kmer). 0:00:44.889 208M / 3G INFO General (edge_index_builders.hpp : 28) Collecting k-mer coverage information from graph, this takes a while. 0:00:49.283 200M / 3G INFO General (graph_construction.hpp : 183) Filling coverage index 0:00:49.283 200M / 3G INFO General (edge_index_builders.hpp : 106) Collecting k-mer coverage information from reads, this takes a while. 0:01:54.476 200M / 3G INFO General (graph_construction.hpp : 185) Filling coverage and flanking coverage from index 0:01:55.156 200M / 3G INFO General (construction.cpp : 34) Figured out: read length = 190 0:01:55.156 200M / 3G INFO StageManager (stage.cpp : 126) STAGE == EC Threshold Finding 0:01:55.239 200M / 3G INFO General (kmer_coverage_model.cpp : 179) Kmer coverage valley at: 15 0:01:55.240 200M / 3G INFO General (kmer_coverage_model.cpp : 199) K-mer histogram maximum: 264 0:01:55.240 200M / 3G INFO General (kmer_coverage_model.cpp : 235) Estimated median coverage: 269. Coverage mad: 44.478 0:01:55.240 200M / 3G INFO General (kmer_coverage_model.cpp : 262) Fitting coverage model 0:01:55.506 200M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 2 0:01:56.255 200M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 4 0:01:59.505 200M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 8 0:02:06.969 200M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 16 0:02:11.975 200M / 3G INFO General (kmer_coverage_model.cpp : 310) Fitted mean coverage: 267.96. Fitted coverage std. dev: 45.2869 0:02:11.982 200M / 3G INFO General (kmer_coverage_model.cpp : 335) Probability of erroneous kmer at valley: 0.999751 0:02:11.982 200M / 3G INFO General (kmer_coverage_model.cpp : 359) Preliminary threshold calculated as: 117 0:02:11.982 200M / 3G INFO General (kmer_coverage_model.cpp : 363) Threshold adjusted to: 117 0:02:11.982 200M / 3G INFO General (kmer_coverage_model.cpp : 376) Estimated genome size (ignoring repeats): 953488 0:02:11.982 200M / 3G INFO General (genomic_info_filler.cpp : 105) Mean coverage was calculated as 267.96 0:02:11.983 200M / 3G INFO General (genomic_info_filler.cpp : 119) EC coverage threshold value was calculated as 117 0:02:11.983 200M / 3G INFO General (genomic_info_filler.cpp : 120) Trusted kmer low bound: 0 0:02:11.983 200M / 3G INFO StageManager (stage.cpp : 126) STAGE == Gap Closer 0:02:11.991 200M / 3G INFO General (gap_closer.cpp : 165) Preparing shift maps 0:02:12.137 220M / 3G INFO General (gap_closer.cpp : 125) Processing paired reads (takes a while) 0:02:30.181 236M / 3G INFO General (gap_closer.cpp : 144) Used 5083354 paired reads 0:02:30.181 236M / 3G INFO General (gap_closer.cpp : 146) Merging paired indices 0:02:30.336 208M / 3G INFO GapCloser (gap_closer.cpp : 403) Closing short gaps 0:02:30.656 208M / 3G INFO GapCloser (gap_closer.cpp : 432) Closing short gaps complete: filled 6 gaps after checking 219 candidates 0:02:30.710 204M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification 0:02:30.718 96M / 3G INFO General (graph_simplification.hpp : 970) Graph simplification started 0:02:30.718 96M / 3G INFO General (graph_simplification.hpp : 975) Fast simplification mode disabled 0:02:30.718 96M / 3G INFO General (graph_simplification.hpp : 695) PROCEDURE == Presimplification 0:02:30.718 96M / 3G INFO General (graph_simplification.hpp : 213) Removing short low covered self-conjugate connections 0:02:30.736 92M / 3G INFO General (graph_simplification.hpp : 699) Further presimplification is disabled 0:02:30.736 92M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 1 0:02:30.838 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:31.466 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:32.036 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:32.683 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 2 0:02:32.733 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:32.806 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:32.934 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:32.966 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 3 0:02:33.006 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:33.070 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:33.143 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:33.174 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 4 0:02:33.211 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:33.275 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:33.359 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:33.390 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 5 0:02:33.427 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:33.492 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:33.566 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:33.599 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 6 0:02:33.636 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:33.700 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:33.771 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:33.801 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 7 0:02:33.838 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:33.909 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:33.981 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:34.014 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 8 0:02:34.050 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:34.114 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:34.187 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:34.217 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 9 0:02:34.257 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:34.324 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:34.395 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:34.425 100M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 10 0:02:34.462 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:34.526 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:34.602 100M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:34.633 100M / 3G INFO General (graph_simplification.hpp : 839) PROCEDURE == Post simplification 0:02:34.633 100M / 3G INFO General (graph_simplification.hpp : 856) Iteration 0 0:02:34.633 100M / 3G INFO General (graph_simplification.hpp : 255) Removal of relatively low covered connections disabled 0:02:34.633 100M / 3G INFO General (graph_simplification.hpp : 530) Complex tip clipping disabled 0:02:34.672 100M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:34.735 100M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:34.776 100M / 3G INFO StageManager (stage.cpp : 126) STAGE == Gap Closer 0:02:34.784 100M / 3G INFO General (graph_pack.hpp : 85) Index refill 0:02:34.784 100M / 3G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:02:34.784 100M / 3G INFO General (kmer_splitters.hpp : 296) Splitting kmer instances into 16 buckets. This might take a while. 0:02:34.784 100M / 3G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:02:34.784 100M / 3G INFO General (kmer_splitters.hpp : 314) Memory available for splitting buffers: 83.3008 Gb 0:02:34.784 100M / 3G INFO General (kmer_splitters.hpp : 319) Using cell size of 2097152 0:02:35.292 676M / 3G INFO General (kmer_splitters.hpp : 332) Processed 97099 edges 0:02:35.292 676M / 3G INFO General (kmer_splitters.hpp : 337) Used 97099 sequences. 0:02:35.297 100M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:02:35.624 100M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 3297380 kmers in total. 0:02:35.624 100M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:02:36.882 100M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:02:37.411 100M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:02:37.667 100M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1077480 bytes occupied (2.61415 bits per kmer). 0:02:37.703 176M / 3G INFO General (edge_index_builders.hpp : 28) Collecting k-mer coverage information from graph, this takes a while. 0:02:40.395 176M / 3G INFO General (gap_closer.cpp : 165) Preparing shift maps 0:02:40.507 192M / 3G INFO General (gap_closer.cpp : 125) Processing paired reads (takes a while) 0:03:00.770 192M / 3G INFO General (gap_closer.cpp : 144) Used 5083354 paired reads 0:03:00.770 192M / 3G INFO General (gap_closer.cpp : 146) Merging paired indices 0:03:00.887 180M / 3G INFO GapCloser (gap_closer.cpp : 403) Closing short gaps 0:03:01.003 180M / 3G INFO GapCloser (gap_closer.cpp : 432) Closing short gaps complete: filled 0 gaps after checking 116 candidates 0:03:01.075 180M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification Cleanup 0:03:01.075 180M / 3G INFO General (graph_simplification.hpp : 406) Removing isolated edges 0:03:01.075 180M / 3G INFO General (graph_simplification.hpp : 407) All edges shorter than 190 will be removed 0:03:01.075 180M / 3G INFO General (graph_simplification.hpp : 408) Also edges shorter than 0 and coverage smaller than 2 will be removed 0:03:03.079 124M / 3G INFO General (simplification.cpp : 88) Counting average coverage 0:03:03.080 124M / 3G INFO General (simplification.cpp : 91) Average coverage = 293.721 0:03:03.080 124M / 3G INFO StageManager (stage.cpp : 126) STAGE == Contig Output 0:03:03.080 124M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K55/simplified_contigs.fasta 0:03:03.113 124M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K55/before_rr.fasta 0:03:03.142 124M / 3G INFO General (contig_output.hpp : 334) Outputting graph to /Volumes/Sequencing/Genomes/assembly/03-Spades//K55/assembly_graph.fastg 0:03:03.201 124M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K55/final_contigs.fasta 0:03:03.231 124M / 3G INFO General (launch.hpp : 112) SPAdes finished 0:03:03.295 16M / 3G INFO General (main.cpp : 168) Assembling time: 0 hours 3 minutes 3 seconds == Running assembler: K77 0:00:00.000 4M / 4M INFO General (memory_limit.hpp : 43) Memory limit set to 250 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 147) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 148) Assembling dataset (/Volumes/Sequencing/Genomes/assembly/03-Spades/dataset.info) with K=77 0:00:00.000 4M / 4M INFO General (launch.hpp : 30) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 31) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 39) Two-step RR enabled: 0 0:00:00.000 4M / 4M INFO General (launch.hpp : 58) Will need read mapping, kmer mapper will be attached 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 126) STAGE == Construction 0:00:00.000 4M / 4M INFO General (construction.cpp : 45) Contigs from previous K will be used 0:00:00.007 4M / 4M INFO General (read_converter.hpp : 49) Binary reads detected 0:00:00.008 4M / 4M INFO General (graph_construction.hpp : 130) Constructing DeBruijn graph for k=77 0:00:00.008 4M / 4M INFO General (kmer_splitters.hpp : 179) Splitting kmer instances into 16 buckets. This might take a while. 0:00:00.008 4M / 4M INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:00.008 4M / 4M INFO General (kmer_splitters.hpp : 197) Memory available for splitting buffers: 20.833 Gb 0:00:00.008 4M / 4M INFO General (kmer_splitters.hpp : 206) Using cell size of 1398101 0:00:09.313 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 7931101 reads 0:00:16.015 2G / 2G INFO General (kmer_splitters.hpp : 235) Processed 11335690 reads 0:00:16.015 2G / 2G INFO General (kmer_splitters.hpp : 241) Adding contigs from previous K 0:00:16.164 2G / 2G INFO General (kmer_splitters.hpp : 252) Used 11335690 reads. Maximum read length 190 0:00:16.164 2G / 2G INFO General (kmer_splitters.hpp : 253) Average read length 105.555 0:00:16.334 16M / 2G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:16.761 16M / 2G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 3907180 kmers in total. 0:00:16.761 16M / 2G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:19.581 16M / 2G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:00:19.581 16M / 2G INFO General (kmer_splitters.hpp : 386) Splitting kmer instances into 64 buckets. This might take a while. 0:00:19.581 16M / 2G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:19.581 16M / 2G INFO General (kmer_splitters.hpp : 404) Memory available for splitting buffers: 20.832 Gb 0:00:19.581 16M / 2G INFO General (kmer_splitters.hpp : 412) Using cell size of 349525 0:00:22.191 3G / 3G INFO General (kmer_splitters.hpp : 435) Processed 3907180 kmers 0:00:22.191 3G / 3G INFO General (kmer_splitters.hpp : 444) Used 3907180 kmers. 0:00:22.210 16M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:23.296 16M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 3944113 kmers in total. 0:00:23.296 16M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:26.108 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:00:26.527 16M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:00:27.105 16M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1288720 bytes occupied (2.61396 bits per kmer). 0:00:27.107 20M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 391) Building k-mer extensions from k+1-mers 0:00:28.717 20M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index.hpp : 395) Building k-mer extensions from k+1-mers finished. 0:00:28.718 20M / 3G INFO General (graph_construction.hpp : 146) Condensing graph 0:00:28.718 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 338) Extracting unbranching paths 0:00:31.070 48M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 352) Extracting unbranching paths finished. 274609 sequences extracted 0:00:31.922 44M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 312) Collecting perfect loops 0:00:32.843 44M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 327) Collecting perfect loops finished. 16 loops collected 0:00:33.069 92M / 3G INFO General (graph_construction.hpp : 151) Building index with from graph 0:00:33.069 92M / 3G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:00:33.069 92M / 3G INFO General (kmer_splitters.hpp : 296) Splitting kmer instances into 16 buckets. This might take a while. 0:00:33.069 92M / 3G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:00:33.069 92M / 3G INFO General (kmer_splitters.hpp : 314) Memory available for splitting buffers: 83.3034 Gb 0:00:33.069 92M / 3G INFO General (kmer_splitters.hpp : 319) Using cell size of 1398101 0:00:33.827 668M / 3G INFO General (kmer_splitters.hpp : 332) Processed 274625 edges 0:00:33.827 668M / 3G INFO General (kmer_splitters.hpp : 337) Used 274625 sequences. 0:00:33.834 92M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:00:34.383 92M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 3907180 kmers in total. 0:00:34.383 92M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:00:36.836 92M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:00:37.610 92M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:00:38.081 92M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 1276664 bytes occupied (2.61399 bits per kmer). 0:00:38.123 184M / 3G INFO General (edge_index_builders.hpp : 28) Collecting k-mer coverage information from graph, this takes a while. 0:00:41.994 180M / 3G INFO General (graph_construction.hpp : 183) Filling coverage index 0:00:41.994 180M / 3G INFO General (edge_index_builders.hpp : 106) Collecting k-mer coverage information from reads, this takes a while. 0:01:23.486 180M / 3G INFO General (graph_construction.hpp : 185) Filling coverage and flanking coverage from index 0:01:23.997 180M / 3G INFO General (construction.cpp : 34) Figured out: read length = 190 0:01:23.997 180M / 3G INFO StageManager (stage.cpp : 126) STAGE == EC Threshold Finding 0:01:24.073 180M / 3G INFO General (kmer_coverage_model.cpp : 179) Kmer coverage valley at: 14 0:01:24.073 180M / 3G INFO General (kmer_coverage_model.cpp : 199) K-mer histogram maximum: 147 0:01:24.073 180M / 3G INFO General (kmer_coverage_model.cpp : 235) Estimated median coverage: 152. Coverage mad: 28.1694 0:01:24.073 180M / 3G INFO General (kmer_coverage_model.cpp : 262) Fitting coverage model 0:01:24.287 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 2 0:01:24.861 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 4 0:01:26.867 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 8 0:01:31.580 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 16 0:01:40.020 180M / 3G INFO General (kmer_coverage_model.cpp : 297) ... iteration 32 0:01:43.674 180M / 3G INFO General (kmer_coverage_model.cpp : 310) Fitted mean coverage: 151.286. Fitted coverage std. dev: 26.8498 0:01:43.679 180M / 3G INFO General (kmer_coverage_model.cpp : 335) Probability of erroneous kmer at valley: 0.99936 0:01:43.679 180M / 3G INFO General (kmer_coverage_model.cpp : 359) Preliminary threshold calculated as: 75 0:01:43.679 180M / 3G INFO General (kmer_coverage_model.cpp : 363) Threshold adjusted to: 75 0:01:43.679 180M / 3G INFO General (kmer_coverage_model.cpp : 376) Estimated genome size (ignoring repeats): 958453 0:01:43.679 180M / 3G INFO General (genomic_info_filler.cpp : 105) Mean coverage was calculated as 151.286 0:01:43.679 180M / 3G INFO General (genomic_info_filler.cpp : 119) EC coverage threshold value was calculated as 75 0:01:43.679 180M / 3G INFO General (genomic_info_filler.cpp : 120) Trusted kmer low bound: 0 0:01:43.679 180M / 3G INFO StageManager (stage.cpp : 126) STAGE == Gap Closer 0:01:43.679 180M / 3G INFO General (gap_closer.cpp : 165) Preparing shift maps 0:01:43.820 196M / 3G INFO General (gap_closer.cpp : 125) Processing paired reads (takes a while) 0:01:57.919 204M / 3G INFO General (gap_closer.cpp : 144) Used 5083354 paired reads 0:01:57.919 204M / 3G INFO General (gap_closer.cpp : 146) Merging paired indices 0:01:58.030 184M / 3G INFO GapCloser (gap_closer.cpp : 403) Closing short gaps 0:01:58.304 188M / 3G INFO GapCloser (gap_closer.cpp : 432) Closing short gaps complete: filled 3 gaps after checking 89 candidates 0:01:58.349 180M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification 0:01:58.357 88M / 3G INFO General (graph_simplification.hpp : 970) Graph simplification started 0:01:58.357 88M / 3G INFO General (graph_simplification.hpp : 975) Fast simplification mode disabled 0:01:58.357 88M / 3G INFO General (graph_simplification.hpp : 695) PROCEDURE == Presimplification 0:01:58.357 88M / 3G INFO General (graph_simplification.hpp : 213) Removing short low covered self-conjugate connections 0:01:58.373 88M / 3G INFO General (graph_simplification.hpp : 699) Further presimplification is disabled 0:01:58.373 88M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 1 0:01:58.460 92M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:01:58.955 92M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:01:59.393 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:01:59.860 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 2 0:01:59.899 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:01:59.971 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:00.085 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:00.122 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 3 0:02:00.161 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:00.227 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:00.304 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:00.337 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 4 0:02:00.375 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:00.442 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:00.517 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:00.555 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 5 0:02:00.593 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:00.665 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:00.740 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:00.772 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 6 0:02:00.810 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:00.879 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:00.953 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:00.986 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 7 0:02:01.023 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:01.089 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:01.163 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:01.195 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 8 0:02:01.238 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:01.315 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:01.390 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:01.423 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 9 0:02:01.464 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:01.531 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:01.607 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:01.639 96M / 3G INFO General (graph_simplification.hpp : 925) PROCEDURE == Simplification cycle, iteration 10 0:02:01.677 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:01.745 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:01.823 96M / 3G INFO General (graph_simplification.hpp : 190) Removing low covered connections 0:02:01.856 96M / 3G INFO General (graph_simplification.hpp : 839) PROCEDURE == Post simplification 0:02:01.856 96M / 3G INFO General (graph_simplification.hpp : 856) Iteration 0 0:02:01.856 96M / 3G INFO General (graph_simplification.hpp : 255) Removal of relatively low covered connections disabled 0:02:01.856 96M / 3G INFO General (graph_simplification.hpp : 530) Complex tip clipping disabled 0:02:01.893 96M / 3G INFO General (graph_simplification.hpp : 96) Clipping tips 0:02:01.959 96M / 3G INFO General (graph_simplification.hpp : 150) Removing bulges 0:02:02.008 96M / 3G INFO StageManager (stage.cpp : 126) STAGE == Gap Closer 0:02:02.008 96M / 3G INFO General (graph_pack.hpp : 85) Index refill 0:02:02.008 96M / 3G INFO K-mer Index Building (kmer_index.hpp : 464) Building kmer index 0:02:02.008 96M / 3G INFO General (kmer_splitters.hpp : 296) Splitting kmer instances into 16 buckets. This might take a while. 0:02:02.008 96M / 3G INFO General (file_limit.hpp : 30) Open file limit set to 256 0:02:02.008 96M / 3G INFO General (kmer_splitters.hpp : 314) Memory available for splitting buffers: 83.3021 Gb 0:02:02.008 96M / 3G INFO General (kmer_splitters.hpp : 319) Using cell size of 1398101 0:02:02.436 672M / 3G INFO General (kmer_splitters.hpp : 332) Processed 103972 edges 0:02:02.436 672M / 3G INFO General (kmer_splitters.hpp : 337) Used 103972 sequences. 0:02:02.441 96M / 3G INFO General (kmer_index.hpp : 342) Starting k-mer counting. 0:02:03.340 96M / 3G INFO General (kmer_index.hpp : 348) K-mer counting done. There are 2463886 kmers in total. 0:02:03.340 96M / 3G INFO General (kmer_index.hpp : 350) Merging temporary buckets. 0:02:04.696 96M / 3G INFO K-mer Index Building (kmer_index.hpp : 473) Building perfect hash indices 0:02:05.057 96M / 3G INFO General (kmer_index.hpp : 368) Merging final buckets. 0:02:05.360 96M / 3G INFO K-mer Index Building (kmer_index.hpp : 521) Index built. Total 805152 bytes occupied (2.61425 bits per kmer). 0:02:05.388 156M / 3G INFO General (edge_index_builders.hpp : 28) Collecting k-mer coverage information from graph, this takes a while. 0:02:07.642 156M / 3G INFO General (gap_closer.cpp : 165) Preparing shift maps 0:02:07.744 172M / 3G INFO General (gap_closer.cpp : 125) Processing paired reads (takes a while) 0:02:22.810 172M / 3G INFO General (gap_closer.cpp : 144) Used 5083354 paired reads 0:02:22.810 172M / 3G INFO General (gap_closer.cpp : 146) Merging paired indices 0:02:22.909 160M / 3G INFO GapCloser (gap_closer.cpp : 403) Closing short gaps 0:02:23.030 160M / 3G INFO GapCloser (gap_closer.cpp : 432) Closing short gaps complete: filled 1 gaps after checking 39 candidates 0:02:23.073 156M / 3G INFO StageManager (stage.cpp : 126) STAGE == Simplification Cleanup 0:02:23.073 156M / 3G INFO General (graph_simplification.hpp : 406) Removing isolated edges 0:02:23.073 156M / 3G INFO General (graph_simplification.hpp : 407) All edges shorter than 190 will be removed 0:02:23.073 156M / 3G INFO General (graph_simplification.hpp : 408) Also edges shorter than 0 and coverage smaller than 2 will be removed 0:02:24.696 100M / 3G INFO General (simplification.cpp : 88) Counting average coverage 0:02:24.696 100M / 3G INFO General (simplification.cpp : 91) Average coverage = 165.508 0:02:24.696 100M / 3G INFO StageManager (stage.cpp : 126) STAGE == Mismatch Correction 0:02:52.694 92M / 3G INFO General (mismatch_shall_not_pass.hp: 189) Finished collecting potential mismatches positions 0:02:52.727 92M / 3G INFO General (mismatch_shall_not_pass.hp: 292) All edges processed 0:02:52.730 92M / 3G INFO General (mismatch_correction.cpp : 19) Corrected 1 nucleotides 0:02:52.730 92M / 3G INFO StageManager (stage.cpp : 126) STAGE == Paired Information Counting 0:02:52.733 92M / 3G INFO General (pair_info_count.cpp : 166) Min edge length for estimation: 26282 0:02:52.733 92M / 3G INFO General (pair_info_count.cpp : 168) Estimating insert size for library #0 0:02:52.733 92M / 3G INFO General (pair_info_count.cpp : 32) Estimating insert size (takes a while) 0:02:52.733 92M / 3G INFO General (short_read_mapper.hpp : 93) Selecting usual mapper 0:02:55.312 92M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 200000 reads 0:02:55.314 92M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 400000 reads 0:02:55.322 92M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 600000 reads 0:02:55.337 92M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 800000 reads 0:02:57.875 92M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 1000000 reads 0:02:57.902 92M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 1200000 reads 0:03:00.558 92M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 2200000 reads 0:03:01.055 92M / 3G INFO General (sequence_mapper_notifier.h: 90) Processed 2541677 reads 0:03:01.055 92M / 3G INFO General (pair_info_count.cpp : 43) 1150012 paired reads (45.2462% of all) aligned to long edges 0:03:01.056 92M / 3G INFO General (pair_info_count.cpp : 186) Estimated insert size for paired library #0 0:03:01.056 92M / 3G INFO General (pair_info_count.cpp : 191) Insert size = 298.74, deviation = 79.6021, left quantile = 209, right quantile = 407, read length = 190 0:03:01.056 92M / 3G INFO General (pair_info_count.cpp : 197) Mapping library #0 0:03:01.065 92M / 3G INFO General (pair_info_count.cpp : 207) Mapping paired reads (takes a while) 0:03:01.065 92M / 3G INFO General (pair_info_count.cpp : 84) Left insert size qauntile 209, right insert size quantile 407 0:03:01.065 92M / 3G INFO General (short_read_mapper.hpp : 93) Selecting usual mapper 0:03:04.403 124M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 200000 reads 0:03:04.466 128M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 400000 reads 0:03:04.603 124M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 600000 reads 0:03:04.733 120M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 800000 reads 0:03:07.921 132M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 1000000 reads 0:03:08.125 128M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 1200000 reads 0:03:12.015 136M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 2200000 reads 0:03:22.079 148M / 3G INFO General (sequence_mapper_notifier.h: 82) Processed 4200000 reads 0:03:24.328 132M / 3G INFO General (sequence_mapper_notifier.h: 90) Processed 5083354 reads 0:03:24.711 132M / 3G INFO General (split_graph_pair_info.hpp : 351) Threshold for paired information 0.207176 0:03:24.742 108M / 3G INFO StageManager (stage.cpp : 126) STAGE == Distance Estimation 0:03:24.743 108M / 3G INFO General (distance_estimation.cpp : 235) Processing library #0 0:03:24.743 108M / 3G INFO General (distance_estimation.cpp : 137) Weight Filter Done 0:03:24.744 108M / 3G INFO DistanceEstimator (distance_estimation.hpp : 188) Using SIMPLE distance estimator 0:03:24.842 108M / 3G INFO DistanceEstimator (distance_estimation.hpp : 209) Merging maps 0:03:24.850 108M / 3G INFO General (distance_estimation.cpp : 39) Filtering info 0:03:24.855 108M / 3G INFO General (pair_info_filters.hpp : 355) Pruning the index 0:03:24.855 108M / 3G INFO General (distance_estimation.cpp : 185) Refining clustered pair information 0:03:24.856 108M / 3G INFO General (distance_estimation.cpp : 187) The refining of clustered pair information has been finished 0:03:24.856 108M / 3G INFO General (distance_estimation.cpp : 189) Improving paired information 0:03:24.894 108M / 3G INFO PairInfoImprover (pair_info_improver.hpp : 62) Paired info stats: missing = 703; contradictional = 268 0:03:24.920 108M / 3G INFO PairInfoImprover (pair_info_improver.hpp : 62) Paired info stats: missing = 14; contradictional = 0 0:03:24.920 108M / 3G INFO General (distance_estimation.cpp : 194) Filling scaffolding index 0:03:24.920 108M / 3G INFO DistanceEstimator (distance_estimation.hpp : 188) Using SMOOTHING distance estimator 0:03:25.092 108M / 3G INFO DistanceEstimator (distance_estimation.hpp : 209) Merging maps 0:03:25.095 108M / 3G INFO General (distance_estimation.cpp : 39) Filtering info 0:03:25.095 108M / 3G INFO General (pair_info_filters.hpp : 355) Pruning the index 0:03:25.101 108M / 3G INFO StageManager (stage.cpp : 126) STAGE == Repeat Resolving 0:03:25.108 108M / 3G INFO General (contig_output.hpp : 297) Outputting contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K77/before_rr.fasta 0:03:25.141 104M / 3G INFO General (contig_output.hpp : 334) Outputting graph to /Volumes/Sequencing/Genomes/assembly/03-Spades//K77/assembly_graph.fastg 0:03:25.201 104M / 3G INFO General (repeat_resolving.cpp : 71) Using Path-Extend repeat resolving 0:03:25.201 104M / 3G INFO General (path_extend_launch.hpp : 460) ExSPAnder repeat resolving tool started 0:03:25.204 104M / 3G INFO General (path_extend_launch.hpp : 472) SUBSTAGE = paired-end libraries 0:03:25.213 104M / 3G INFO General (path_extend_launch.hpp : 320) Threshold for library #0 is 0.207176 0:03:25.214 104M / 3G INFO General (path_extend_launch.hpp : 422) Using 1 paired-end library 0:03:25.214 104M / 3G INFO General (path_extend_launch.hpp : 423) Using 1 paired-end scaffolding library 0:03:25.214 104M / 3G INFO General (path_extend_launch.hpp : 424) Using 0 mate-pair libraries 0:03:25.214 104M / 3G INFO General (path_extend_launch.hpp : 425) Using 0 single read libraries 0:03:25.214 104M / 3G INFO General (path_extend_launch.hpp : 426) Scaffolder is on 0:03:25.216 108M / 3G INFO General (path_extend_launch.hpp : 483) Growing paths using paired-end and long single reads 0:03:25.216 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 0 paths from 476 (0%) 0:03:25.265 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 48 paths from 476 (10%) 0:03:25.292 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 96 paths from 476 (20%) 0:03:25.301 108M / 3G INFO PathExtender (path_extender.hpp : 668) Processed 128 paths from 476 (26%) 0:03:25.302 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 144 paths from 476 (30%) 0:03:25.312 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 192 paths from 476 (40%) 0:03:25.320 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 240 paths from 476 (50%) 0:03:25.327 108M / 3G INFO PathExtender (path_extender.hpp : 668) Processed 256 paths from 476 (53%) 0:03:25.336 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 288 paths from 476 (60%) 0:03:25.345 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 336 paths from 476 (70%) 0:03:25.346 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 384 paths from 476 (80%) 0:03:25.346 108M / 3G INFO PathExtender (path_extender.hpp : 670) Processed 432 paths from 476 (90%) 0:03:25.359 112M / 3G INFO PathExtendIO (pe_io.hpp : 173) Writing contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K77/final_contigs 0:03:25.396 112M / 3G INFO PathExtendIO (pe_io.hpp : 173) Writing contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K77/path_extend/pe_before_traversal 0:03:25.430 112M / 3G INFO General (path_extend_launch.hpp : 222) Traversing tandem repeats 0:03:25.433 112M / 3G INFO PathExtendIO (pe_io.hpp : 173) Writing contigs to /Volumes/Sequencing/Genomes/assembly/03-Spades//K77/scaffolds 0:03:25.507 108M / 3G INFO General (launch.hpp : 112) SPAdes finished 0:03:25.575 20M / 3G INFO General (main.cpp : 168) Assembling time: 0 hours 3 minutes 25 seconds ===== Assembling finished. ===== Mismatch correction started. == Processing of contigs == Running contig polishing tool: /Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/corrector /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/configs/corrector.info /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_contigs.fasta == Dataset description file was created: /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/configs/corrector.info 0:00:00.025 4M / 4M INFO General (main.cpp : 48) Starting MismatchCorrector, built from N/A, git revision N/A 0:00:00.025 4M / 4M INFO General (dataset_processor.cpp : 236) Splitting assembly... 0:00:00.025 4M / 4M INFO General (dataset_processor.cpp : 237) Assembly file: /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_contigs.fasta 0:00:00.075 4M / 4M INFO General (dataset_processor.cpp : 244) Processing paired sublib of number 0 0:00:00.075 4M / 4M INFO General (dataset_processor.cpp : 247) /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq 0:00:00.075 4M / 4M INFO General (dataset_processor.cpp : 143) Running bwa index ...: /Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades index -a is /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_contigs.fasta 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/tmp/lib0_C0aUeu/bwa.flood 0:00:00.434 4M / 4M INFO General (dataset_processor.cpp : 166) Running bwa mem ...:/Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades mem /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_contigs.fasta /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq -t 4 > /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/tmp/lib0_C0aUeu/tmp.sam 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/tmp/lib0_C0aUeu/isize.txt 0:00:00.447 4M / 4M INFO General (dataset_processor.cpp : 169) bwa failed, skipping sublib 0:00:00.447 4M / 4M WARN General (dataset_processor.cpp : 256) Failed to align paired reads /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq and /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq 0:00:00.447 4M / 4M INFO General (dataset_processor.cpp : 260) Processing single sublib of number 0 0:00:00.447 4M / 4M INFO General (dataset_processor.cpp : 262) /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq 0:00:00.447 4M / 4M INFO General (dataset_processor.cpp : 190) Running bwa index ...: /Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades index -a is /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_contigs.fasta 2 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/tmp/lib0_C0aUeu/bwa.flood 0:00:00.785 4M / 4M INFO General (dataset_processor.cpp : 209) Running bwa mem ...:/Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades mem /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_contigs.fasta /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq -t 4 > /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/tmp/lib0_C0aUeu/tmp.sam 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/contigs/tmp/lib0_C0aUeu/isize.txt 0:00:00.789 4M / 4M INFO General (dataset_processor.cpp : 212) bwa failed, skipping sublib 0:00:00.789 4M / 4M WARN General (dataset_processor.cpp : 271) Failed to align single reads /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq 0:00:00.789 4M / 4M INFO General (dataset_processor.cpp : 276) Processing contigs 0:00:00.819 64M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_4_length_49374_cov_135.734_ID_13003 processed with 0 changes in thread 2 0:00:00.821 60M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_3_length_53303_cov_177.606_ID_13001 processed with 0 changes in thread 1 0:00:00.823 60M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_2_length_53431_cov_196.037_ID_12999 processed with 0 changes in thread 3 0:00:00.825 60M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_1_length_63176_cov_140.479_ID_12997 processed with 0 changes in thread 0 0:00:00.848 36M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_7_length_33846_cov_142.195_ID_13009 processed with 0 changes in thread 0 0:00:00.850 36M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_6_length_36608_cov_165.82_ID_13007 processed with 0 changes in thread 1 0:00:00.850 36M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_5_length_45551_cov_144.05_ID_13005 processed with 0 changes in thread 2 0:00:00.852 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_8_length_33594_cov_164.896_ID_13011 processed with 0 changes in thread 3 0:00:00.864 32M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_9_length_32360_cov_138.717_ID_13013 processed with 0 changes in thread 0 0:00:00.869 32M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_11_length_31299_cov_150.054_ID_13017 processed with 0 changes in thread 3 0:00:00.869 32M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_10_length_31821_cov_166.735_ID_13015 processed with 0 changes in thread 2 0:00:00.876 20M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_12_length_31177_cov_217.971_ID_13019 processed with 0 changes in thread 1 0:00:00.885 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_13_length_28802_cov_188.692_ID_13021 processed with 0 changes in thread 0 0:00:00.885 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_15_length_26853_cov_146.908_ID_13025 processed with 0 changes in thread 2 0:00:00.888 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_14_length_27680_cov_146.64_ID_13023 processed with 0 changes in thread 3 0:00:00.891 24M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_16_length_26757_cov_178.681_ID_13027 processed with 0 changes in thread 1 0:00:00.899 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_17_length_24551_cov_175.407_ID_13029 processed with 0 changes in thread 2 0:00:00.900 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_18_length_24395_cov_159.996_ID_13031 processed with 0 changes in thread 1 0:00:00.902 24M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_19_length_21735_cov_145.803_ID_13033 processed with 0 changes in thread 3 0:00:01.001 16M / 64M INFO General (dataset_processor.cpp : 296) Gluing processed contigs 0:00:01.006 16M / 64M INFO General (main.cpp : 57) Correcting time: 0 hours 0 minutes 1 seconds == Processing of scaffolds == Running contig polishing tool: /Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/corrector /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/configs/corrector.info /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_scaffolds.fasta == Dataset description file was created: /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/configs/corrector.info 0:00:00.000 4M / 4M INFO General (main.cpp : 48) Starting MismatchCorrector, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (dataset_processor.cpp : 236) Splitting assembly... 0:00:00.000 4M / 4M INFO General (dataset_processor.cpp : 237) Assembly file: /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_scaffolds.fasta 0:00:00.135 4M / 4M INFO General (dataset_processor.cpp : 244) Processing paired sublib of number 0 0:00:00.135 4M / 4M INFO General (dataset_processor.cpp : 247) /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq 0:00:00.135 4M / 4M INFO General (dataset_processor.cpp : 143) Running bwa index ...: /Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades index -a is /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_scaffolds.fasta 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/tmp/lib0_lVWOtF/bwa.flood 0:00:00.480 4M / 4M INFO General (dataset_processor.cpp : 166) Running bwa mem ...:/Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades mem /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_scaffolds.fasta /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq -t 4 > /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/tmp/lib0_lVWOtF/tmp.sam 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/tmp/lib0_lVWOtF/isize.txt 0:00:00.485 4M / 4M INFO General (dataset_processor.cpp : 169) bwa failed, skipping sublib 0:00:00.485 4M / 4M WARN General (dataset_processor.cpp : 256) Failed to align paired reads /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq and /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq 0:00:00.485 4M / 4M INFO General (dataset_processor.cpp : 260) Processing single sublib of number 0 0:00:00.485 4M / 4M INFO General (dataset_processor.cpp : 262) /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq 0:00:00.485 4M / 4M INFO General (dataset_processor.cpp : 190) Running bwa index ...: /Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades index -a is /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_scaffolds.fasta 2 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/tmp/lib0_lVWOtF/bwa.flood 0:00:00.825 4M / 4M INFO General (dataset_processor.cpp : 209) Running bwa mem ...:/Users/Joey/opt/SPAdes-3.6.2-Darwin/bin/bwa-spades mem /Volumes/Sequencing/Genomes/assembly/03-Spades/misc/assembled_scaffolds.fasta /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq -t 4 > /Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/tmp/lib0_lVWOtF/tmp.sam 2>/Volumes/Sequencing/Genomes/assembly/03-Spades/mismatch_corrector/scaffolds/tmp/lib0_lVWOtF/isize.txt 0:00:00.829 4M / 4M INFO General (dataset_processor.cpp : 212) bwa failed, skipping sublib 0:00:00.829 4M / 4M WARN General (dataset_processor.cpp : 271) Failed to align single reads /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq 0:00:00.829 4M / 4M INFO General (dataset_processor.cpp : 276) Processing contigs 0:00:00.851 64M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_4_length_49374_cov_135.734_ID_1829 processed with 0 changes in thread 3 0:00:00.852 64M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_3_length_53303_cov_177.606_ID_1075 processed with 0 changes in thread 1 0:00:00.853 64M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_2_length_53431_cov_196.037_ID_953 processed with 0 changes in thread 2 0:00:00.855 60M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_1_length_63176_cov_140.479_ID_1267 processed with 0 changes in thread 0 0:00:00.876 32M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_6_length_36608_cov_165.82_ID_1421 processed with 0 changes in thread 1 0:00:00.879 36M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_7_length_33846_cov_142.195_ID_1515 processed with 0 changes in thread 2 0:00:00.881 36M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_8_length_33594_cov_164.896_ID_2788 processed with 0 changes in thread 0 0:00:00.887 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_5_length_45551_cov_144.05_ID_1201 processed with 0 changes in thread 3 0:00:00.898 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_9_length_32360_cov_138.717_ID_1923 processed with 0 changes in thread 1 0:00:00.899 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_10_length_31821_cov_166.735_ID_2997 processed with 0 changes in thread 2 0:00:00.899 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_11_length_31299_cov_150.054_ID_1617 processed with 0 changes in thread 0 0:00:00.907 20M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_12_length_31177_cov_217.971_ID_1723 processed with 0 changes in thread 3 0:00:00.916 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_14_length_27680_cov_146.64_ID_2159 processed with 0 changes in thread 0 0:00:00.916 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_13_length_28802_cov_188.692_ID_2017 processed with 0 changes in thread 2 0:00:00.917 32M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_15_length_26853_cov_146.908_ID_2250 processed with 0 changes in thread 1 0:00:00.922 20M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_16_length_26757_cov_178.681_ID_2372 processed with 0 changes in thread 3 0:00:00.930 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_17_length_24551_cov_175.407_ID_2580 processed with 0 changes in thread 0 0:00:00.931 32M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_18_length_24395_cov_159.996_ID_2490 processed with 0 changes in thread 2 0:00:00.933 28M / 64M INFO General (dataset_processor.cpp : 292) Contig NODE_19_length_21735_cov_145.803_ID_11613 processed with 0 changes in thread 1 0:00:00.995 16M / 64M INFO General (dataset_processor.cpp : 296) Gluing processed contigs 0:00:01.003 16M / 64M INFO General (main.cpp : 57) Correcting time: 0 hours 0 minutes 1 seconds ===== Mismatch correction finished. * Corrected reads are in /Volumes/Sequencing/Genomes/assembly/03-Spades/corrected/ * Assembled contigs are in /Volumes/Sequencing/Genomes/assembly/03-Spades/contigs.fasta * Assembled scaffolds are in /Volumes/Sequencing/Genomes/assembly/03-Spades/scaffolds.fasta * Assembly graph is in /Volumes/Sequencing/Genomes/assembly/03-Spades/assembly_graph.fastg * Paths in the assembly graph corresponding to the contigs are in /Volumes/Sequencing/Genomes/assembly/03-Spades/contigs.paths * Paths in the assembly graph corresponding to the scaffolds are in /Volumes/Sequencing/Genomes/assembly/03-Spades/scaffolds.paths ======= SPAdes pipeline finished WITH WARNINGS! === Pipeline warnings: * Default k-mer sizes were set to [21, 33, 55, 77] because estimated read length (190) is equal to or greater than 150 === Error correction and assembling warnings: * 0:00:00.447 4M / 4M WARN General (dataset_processor.cpp : 256) Failed to align paired reads /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq and /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq * 0:00:00.789 4M / 4M WARN General (dataset_processor.cpp : 271) Failed to align single reads /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq ======= Warnings saved to /Volumes/Sequencing/Genomes/assembly/03-Spades/warnings.log SPAdes log can be found here: /Volumes/Sequencing/Genomes/assembly/03-Spades/spades.log Thank you for using SPAdes! spades.py -1 /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R1.fastq -2 /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_R2.fastq -s /Volumes/Sequencing/Genomes/assembly/02-Cleaned/2133MB/2133MB_SE.fastq --careful -t 10 -o 03-Spades -m 250 Seconds: 1828.1234982 Total amount of seconds to run all samples Seconds: 0