centos:centos6 quay.io/biocontainers/spades:3.13.1--h2d02072_2 using docker + set -o pipefail + pairinput= + '[' input_1 '!=' '' ']' ++ find input_1/ ++ egrep '(_R1.*|_1)[.]f(ast|)q([.]gz|)$' + r1=input_1/DRR015801_1.fastq.gz ++ for i in '$r1' +++ echo input_1/DRR015801_1.fastq.gz +++ wc -l +++ egrep '_1[.]f(ast|)q([.]gz|)$' ++ '[' 1 = 1 ']' ++ echo input_1/DRR015801_1.fastq.gz ++ sed 's/_1[.]f\(ast\|\)q\([.]gz\|\)/_2.f\1q\2/' + r2=input_1/DRR015801_2.fastq.gz + echo '#Check paired-end' #Check paired-end + ls input_1/DRR015801_2.fastq.gz + n=0 + r1input= + for i in '$r1' ++ expr 0 + 1 + n=1 + r1input=' --pe1-1 input_1/DRR015801_1.fastq.gz' + n=0 + r2input= + for i in '$r2' ++ expr 0 + 1 + n=1 + r2input=' --pe1-2 input_1/DRR015801_2.fastq.gz' + '[' ' --pe1-1 input_1/DRR015801_1.fastq.gz' '!=' '' ']' + pairinput=' --pe1-1 input_1/DRR015801_1.fastq.gz --pe1-2 input_1/DRR015801_2.fastq.gz' + singleinput= + '[' '' '!=' '' ']' + docker run -v /tmp/183:/tmp/183 -w /tmp/183 -u root -i --rm quay.io/biocontainers/spades:3.13.1--h2d02072_2 spades.py -o output_dir -t 8 -m 25 --pe1-1 input_1/DRR015801_1.fastq.gz --pe1-2 input_1/DRR015801_2.fastq.gz Command line: /usr/local/bin/spades.py -o /tmp/183/output_dir -t 8 -m 25 --pe1-1 /tmp/183/input_1/DRR015801_1.fastq.gz --pe1-2 /tmp/183/input_1/DRR015801_2.fastq.gz System information: SPAdes version: 3.13.1 Python version: 3.7.3 OS: Linux-3.10.0-1062.el7.x86_64-x86_64-with-glibc2.10 Output dir: /tmp/183/output_dir 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 or --meta flag if processing metagenomic dataset) Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/tmp/183/input_1/DRR015801_1.fastq.gz'] right reads: ['/tmp/183/input_1/DRR015801_2.fastq.gz'] interlaced reads: not specified single reads: not specified merged reads: not specified Read error correction parameters: Iterations: 1 PHRED offset will be auto-detected Corrected reads will be compressed Assembly parameters: k: automatic selection based on read length Repeat resolution is enabled Mismatch careful mode is turned OFF MismatchCorrector will be SKIPPED Coverage cutoff is turned OFF Other parameters: Dir for temp files: /tmp/183/output_dir/tmp Threads: 8 Memory limit (in Gb): 25 ======= SPAdes pipeline started. Log can be found here: /tmp/183/output_dir/spades.log ===== Read error correction started. == Running read error correction tool: /usr/local/bin/spades-hammer /tmp/183/output_dir/corrected/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 75) Starting BayesHammer, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 76) Loading config from /tmp/183/output_dir/corrected/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 78) Maximum # of threads to use (adjusted due to OMP capabilities): 8 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 25 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 86) Trying to determine PHRED offset 0:00:00.000 4M / 4M INFO General (main.cpp : 92) Determined value is 33 0:00:00.000 4M / 4M INFO General (hammer_tools.cpp : 36) Hamming graph threshold tau=1, k=21, subkmer positions = [ 0 10 ] 0:00:00.000 4M / 4M INFO General (main.cpp : 113) Size of aux. kmer data 24 bytes === ITERATION 0 begins === 0:00:00.001 4M / 4M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:00.001 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. 0:00:00.001 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:00:00.001 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.0415 Gb 0:00:00.001 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:00:00.002 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /tmp/183/input_1/DRR015801_1.fastq.gz 0:00:19.856 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 2627174 reads 0:00:39.265 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 5258029 reads 0:00:59.006 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 7821422 reads 0:01:15.030 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 9923537 reads 0:01:15.031 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /tmp/183/input_1/DRR015801_2.fastq.gz 0:01:34.525 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 12559487 reads 0:01:53.822 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 15137753 reads 0:02:13.530 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 17831332 reads 0:02:27.672 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 19847074 reads 0:02:27.672 8G / 8G INFO K-mer Splitting (kmer_data.cpp : 112) Total 19847074 reads processed 0:02:28.106 32M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:02:30.474 32M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 84218672 kmers in total. 0:02:30.474 32M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:02:31.117 32M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:02:35.646 64M / 8G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:02:36.253 64M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 39060248 bytes occupied (3.71036 bits per kmer). 0:02:36.253 64M / 8G INFO K-mer Counting (kmer_data.cpp : 356) Arranging kmers in hash map order 0:02:40.023 1G / 8G INFO General (main.cpp : 148) Clustering Hamming graph. 0:05:56.131 1G / 8G INFO General (main.cpp : 155) Extracting clusters 0:06:32.819 1G / 8G INFO General (main.cpp : 167) Clustering done. Total clusters: 39101719 0:06:32.872 708M / 8G INFO K-mer Counting (kmer_data.cpp : 376) Collecting K-mer information, this takes a while. 0:06:33.557 2G / 8G INFO K-mer Counting (kmer_data.cpp : 382) Processing /tmp/183/input_1/DRR015801_1.fastq.gz 0:09:55.898 2G / 8G INFO K-mer Counting (kmer_data.cpp : 382) Processing /tmp/183/input_1/DRR015801_2.fastq.gz 0:13:16.409 2G / 8G INFO K-mer Counting (kmer_data.cpp : 389) Collection done, postprocessing. 0:13:16.801 2G / 8G INFO K-mer Counting (kmer_data.cpp : 403) There are 84218672 kmers in total. Among them 65419030 (77.6776%) are singletons. 0:13:16.801 2G / 8G INFO General (main.cpp : 173) Subclustering Hamming graph 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 649) Subclustering done. Total 2461 non-read kmers were generated. 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 650) Subclustering statistics: 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 651) Total singleton hamming clusters: 29044690. Among them 5094690 (17.5409%) are good 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 652) Total singleton subclusters: 35002. Among them 34626 (98.9258%) are good 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 653) Total non-singleton subcluster centers: 10530544. Among them 8170052 (77.5843%) are good 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 654) Average size of non-trivial subcluster: 5.23984 kmers 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 655) Average number of sub-clusters per non-singleton cluster: 1.05056 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 656) Total solid k-mers: 13299368 0:16:44.680 2G / 8G INFO Hamming Subclustering (kmer_cluster.cpp : 657) Substitution probabilities: [4,4]((0.934954,0.0260761,0.024855,0.0141146),(0.0181358,0.945293,0.0166783,0.0198931),(0.0195422,0.0163928,0.945491,0.0185741),(0.0137965,0.024537,0.0258154,0.935851)) 0:16:44.762 2G / 8G INFO General (main.cpp : 178) Finished clustering. 0:16:44.762 2G / 8G INFO General (main.cpp : 197) Starting solid k-mers expansion in 8 threads. 0:19:27.293 2G / 8G INFO General (main.cpp : 218) Solid k-mers iteration 0 produced 2733399 new k-mers. 0:22:09.313 2G / 8G INFO General (main.cpp : 218) Solid k-mers iteration 1 produced 195164 new k-mers. 0:24:51.002 2G / 8G INFO General (main.cpp : 218) Solid k-mers iteration 2 produced 9293 new k-mers. 0:27:38.788 2G / 8G INFO General (main.cpp : 218) Solid k-mers iteration 3 produced 1421 new k-mers. 0:30:28.785 2G / 8G INFO General (main.cpp : 218) Solid k-mers iteration 4 produced 248 new k-mers. 0:33:19.450 2G / 8G INFO General (main.cpp : 218) Solid k-mers iteration 5 produced 129 new k-mers. 0:36:09.927 2G / 8G INFO General (main.cpp : 218) Solid k-mers iteration 6 produced 8 new k-mers. 0:36:09.927 2G / 8G INFO General (main.cpp : 222) Solid k-mers finalized 0:36:09.927 2G / 8G INFO General (hammer_tools.cpp : 220) Starting read correction in 8 threads. 0:36:09.927 2G / 8G INFO General (hammer_tools.cpp : 233) Correcting pair of reads: /tmp/183/input_1/DRR015801_1.fastq.gz and /tmp/183/input_1/DRR015801_2.fastq.gz 0:36:16.282 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 0 of 800000 reads. 0:36:31.316 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 0 0:36:33.149 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 0 0:36:38.980 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 1 of 800000 reads. 0:36:53.308 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 1 0:36:55.159 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 1 0:37:00.982 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 2 of 800000 reads. 0:37:15.876 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 2 0:37:17.735 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 2 0:37:23.555 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 3 of 800000 reads. 0:37:37.705 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 3 0:37:39.566 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 3 0:37:45.369 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 4 of 800000 reads. 0:38:00.443 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 4 0:38:02.316 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 4 0:38:08.129 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 5 of 800000 reads. 0:38:22.710 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 5 0:38:24.627 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 5 0:38:30.447 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 6 of 800000 reads. 0:38:46.163 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 6 0:38:48.027 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 6 0:38:53.831 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 7 of 800000 reads. 0:39:09.161 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 7 0:39:11.082 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 7 0:39:16.881 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 8 of 800000 reads. 0:39:32.384 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 8 0:39:34.282 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 8 0:39:40.081 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 9 of 800000 reads. 0:39:54.787 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 9 0:39:56.711 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 9 0:40:02.580 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 10 of 800000 reads. 0:40:18.708 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 10 0:40:20.585 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 10 0:40:26.400 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 11 of 800000 reads. 0:40:42.327 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 11 0:40:44.187 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 11 0:40:46.550 3G / 8G INFO General (hammer_tools.cpp : 168) Prepared batch 12 of 323537 reads. 0:40:53.481 3G / 8G INFO General (hammer_tools.cpp : 175) Processed batch 12 0:40:54.245 3G / 8G INFO General (hammer_tools.cpp : 185) Written batch 12 0:40:54.814 2G / 8G INFO General (hammer_tools.cpp : 274) Correction done. Changed 2639127 bases in 1220234 reads. 0:40:54.814 2G / 8G INFO General (hammer_tools.cpp : 275) Failed to correct 388215 bases out of 1984664993. 0:40:55.150 32M / 8G INFO General (main.cpp : 255) Saving corrected dataset description to /tmp/183/output_dir/corrected/corrected.yaml 0:40:55.152 32M / 8G INFO General (main.cpp : 262) All done. Exiting. == Compressing corrected reads (with gzip) == Dataset description file was created: /tmp/183/output_dir/corrected/corrected.yaml ===== Read error correction finished. ===== Assembling started. == Running assembler: K21 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /tmp/183/output_dir/K21/configs/config.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 25 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.000 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/tmp/183/output_dir/dataset.info) with K=21 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 8 0:00:00.000 4M / 4M INFO General (launch.hpp : 52) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 59) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 66) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.002 4M / 4M INFO General (read_converter.hpp : 77) Converting reads to binary format for library #0 (takes a while) 0:00:00.002 4M / 4M INFO General (read_converter.hpp : 78) Converting paired reads 0:00:00.288 76M / 76M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:00:00.497 88M / 88M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:00:00.915 104M / 104M INFO General (binary_converter.hpp : 93) 65536 reads processed 0:00:01.755 144M / 144M INFO General (binary_converter.hpp : 93) 131072 reads processed 0:00:03.431 220M / 220M INFO General (binary_converter.hpp : 93) 262144 reads processed 0:00:07.695 284M / 284M INFO General (binary_converter.hpp : 93) 524288 reads processed 0:00:16.155 308M / 308M INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:00:32.034 332M / 332M INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:01:04.638 332M / 332M INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:02:09.847 324M / 332M INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:02:32.870 252M / 332M INFO General (binary_converter.hpp : 117) 9863664 reads written 0:02:33.118 4M / 332M INFO General (read_converter.hpp : 87) Converting single reads 0:02:33.365 136M / 332M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:02:33.471 140M / 332M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:02:33.744 148M / 332M INFO General (binary_converter.hpp : 117) 57230 reads written 0:02:33.791 4M / 332M INFO General (read_converter.hpp : 95) Converting merged reads 0:02:33.952 132M / 332M INFO General (binary_converter.hpp : 117) 0 reads written 0:02:33.975 4M / 332M INFO General (construction.cpp : 111) Max read length 100 0:02:33.975 4M / 332M INFO General (construction.cpp : 117) Average read length 99.9798 0:02:33.975 4M / 332M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:02:33.975 4M / 332M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. 0:02:33.975 4M / 332M INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:02:33.975 4M / 332M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.0415 Gb 0:02:33.975 4M / 332M INFO General (kmer_splitters.hpp : 97) Using cell size of 1048576 0:02:53.036 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 12801941 reads 0:03:11.954 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 25591270 reads 0:03:30.820 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 38389677 reads 0:03:32.829 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 39569116 reads 0:03:32.829 6G / 6G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:03:33.680 32M / 6G INFO General (kmer_splitters.hpp : 308) Used 39569116 reads 0:03:33.680 32M / 6G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:03:34.500 32M / 6G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 16336387 kmers in total. 0:03:34.501 32M / 6G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:03:34.669 32M / 6G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:03:34.669 32M / 6G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:03:34.669 32M / 6G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. 0:03:34.669 32M / 6G INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:03:34.669 32M / 6G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.04036 Gb 0:03:34.669 32M / 6G INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:03:36.506 8G / 8G INFO General (kmer_splitters.hpp : 380) Processed 16336387 kmers 0:03:36.507 8G / 8G INFO General (kmer_splitters.hpp : 385) Used 16336387 kmers. 0:03:36.607 32M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:03:36.925 32M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 15850335 kmers in total. 0:03:36.925 32M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:03:37.070 32M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:03:37.837 32M / 8G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:03:37.996 32M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 7357824 bytes occupied (3.71365 bits per kmer). 0:03:38.009 48M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:03:40.158 48M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:03:40.159 48M / 8G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:03:40.159 48M / 8G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:03:40.159 48M / 8G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:03:45.451 48M / 8G INFO Early tip clipping (early_simplification.hpp : 184) 3077586 22-mers were removed by early tip clipper 0:03:45.451 48M / 8G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:03:45.484 48M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:03:48.440 124M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1316238 sequences extracted 0:03:49.703 124M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:03:50.346 124M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 26 loops collected 0:03:51.127 400M / 8G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:03:51.127 400M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:03:51.127 400M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:03:52.055 404M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 7579208 bytes occupied (3.71157 bits per kmer). 0:03:52.086 468M / 8G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:05:30.181 468M / 8G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:05:32.125 468M / 8G INFO General (construction.cpp : 464) Processed 2632165 edges 0:05:32.242 380M / 8G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:05:32.254 380M / 8G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 57 0:05:32.255 380M / 8G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 161 0:05:32.255 380M / 8G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 163. Coverage mad: 32.6172 0:05:32.256 380M / 8G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:05:32.462 380M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:05:32.966 380M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:05:35.268 380M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:05:40.064 380M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:05:42.565 380M / 8G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 164.625. Fitted coverage std. dev: 31.0269 0:05:42.570 380M / 8G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.970949 0:05:42.570 380M / 8G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 107 0:05:42.570 380M / 8G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 107 0:05:42.570 380M / 8G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 5005043 0:05:42.570 380M / 8G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 164.625 0:05:42.570 380M / 8G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 107 0:05:42.570 380M / 8G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:05:42.570 380M / 8G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:05:42.571 380M / 8G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:05:42.571 380M / 8G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 0:05:42.571 380M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:05:42.721 380M / 8G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:05:42.722 380M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial tip clipper 0:05:43.112 376M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial tip clipper triggered 8323 times 0:05:43.112 376M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial ec remover 0:05:59.994 412M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial ec remover triggered 384269 times 0:05:59.994 412M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial isolated edge remover 0:06:00.133 412M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial isolated edge remover triggered 11954 times 0:06:00.256 404M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:06:00.256 404M / 8G INFO General (simplification.cpp : 357) Graph simplification started 0:06:00.256 404M / 8G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:06:00.256 404M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:06:00.256 404M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:00.351 404M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2468 times 0:06:00.351 404M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:10.895 404M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 15262 times 0:06:10.895 404M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:14.984 332M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 77569 times 0:06:14.984 332M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:06:14.984 332M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:15.035 328M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 298 times 0:06:15.035 328M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:16.915 304M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 4893 times 0:06:16.915 304M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:17.320 264M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 7745 times 0:06:17.320 264M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:06:17.320 264M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:17.332 260M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 8 times 0:06:17.332 260M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:17.744 244M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1059 times 0:06:17.744 244M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:17.900 228M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2645 times 0:06:17.901 228M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:06:17.901 228M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:17.905 228M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:17.905 228M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.036 216M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 380 times 0:06:18.036 216M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.102 204M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1264 times 0:06:18.102 204M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:06:18.102 204M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.105 204M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.105 204M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.163 200M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 165 times 0:06:18.163 200M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.202 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 699 times 0:06:18.202 192M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:06:18.202 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.204 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:06:18.204 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.229 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 84 times 0:06:18.229 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.255 172M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 476 times 0:06:18.255 172M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:06:18.255 172M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.256 172M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.256 172M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.272 172M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 50 times 0:06:18.272 172M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.289 168M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 330 times 0:06:18.289 168M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:06:18.289 168M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.290 168M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.290 168M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.302 168M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 27 times 0:06:18.302 168M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.319 168M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 242 times 0:06:18.319 168M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:06:18.319 168M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.320 168M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.320 168M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.330 168M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 43 times 0:06:18.330 168M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.341 164M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 156 times 0:06:18.341 164M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:06:18.341 164M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.341 164M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.341 164M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.348 164M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 15 times 0:06:18.348 164M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.358 164M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 144 times 0:06:18.358 164M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:06:18.358 164M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.361 164M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:06:18.361 164M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.397 164M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 18 times 0:06:18.397 164M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.408 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:06:18.408 160M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:06:18.408 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.408 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.408 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.409 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:06:18.409 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:06:18.409 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:06:18.409 160M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:06:18.409 160M / 8G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:06:18.409 160M / 8G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 0:06:18.409 160M / 8G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 0:06:18.409 160M / 8G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:06:18.409 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.412 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.412 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.442 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:06:18.442 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:06:18.446 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:06:18.446 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:06:18.473 160M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:06:18.473 160M / 8G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:06:18.488 160M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:06:18.529 124M / 8G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 1604 times 0:06:18.529 124M / 8G INFO General (simplification.cpp : 470) Counting average coverage 0:06:18.535 124M / 8G INFO General (simplification.cpp : 476) Average coverage = 295.177 0:06:18.535 124M / 8G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:06:18.535 124M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /tmp/183/output_dir//K21/simplified_contigs.fasta 0:06:18.642 120M / 8G INFO General (launch.hpp : 151) SPAdes finished 0:06:18.800 36M / 8G INFO General (main.cpp : 109) Assembling time: 0 hours 6 minutes 18 seconds Max read length detected as 100 == Running assembler: K33 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /tmp/183/output_dir/K33/configs/config.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 25 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.000 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/tmp/183/output_dir/dataset.info) with K=33 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 8 0:00:00.000 4M / 4M INFO General (launch.hpp : 52) SPAdes started 0:00:00.000 4M / 4M INFO General (launch.hpp : 59) Starting from stage: construction 0:00:00.000 4M / 4M INFO General (launch.hpp : 66) Two-step RR enabled: 0 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.000 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.001 4M / 4M INFO General (construction.cpp : 111) Max read length 100 0:00:00.001 4M / 4M INFO General (construction.cpp : 117) Average read length 99.9798 0:00:00.001 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.001 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. 0:00:00.001 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:00:00.001 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.0415 Gb 0:00:00.001 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:00:11.614 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 7561150 reads 0:00:22.835 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 15116056 reads 0:00:34.118 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 22673048 reads 0:00:45.176 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 30228442 reads 0:00:56.132 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 37788102 reads 0:00:58.911 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 39569116 reads 0:00:58.911 6G / 6G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:01:00.903 32M / 6G INFO General (kmer_splitters.hpp : 308) Used 39569116 reads 0:01:00.903 32M / 6G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:01:02.374 32M / 6G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 21719732 kmers in total. 0:01:02.375 32M / 6G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:01:02.835 32M / 6G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:01:02.835 32M / 6G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:01:02.835 32M / 6G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. 0:01:02.836 32M / 6G INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:01:02.836 32M / 6G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.04036 Gb 0:01:02.836 32M / 6G INFO General (kmer_splitters.hpp : 97) Using cell size of 262144 0:01:05.680 8G / 8G INFO General (kmer_splitters.hpp : 380) Processed 21719732 kmers 0:01:05.680 8G / 8G INFO General (kmer_splitters.hpp : 385) Used 21719732 kmers. 0:01:05.877 32M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:01:06.499 32M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 21330362 kmers in total. 0:01:06.500 32M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:01:06.927 32M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:01:08.047 32M / 8G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:01:08.473 32M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 9899064 bytes occupied (3.71267 bits per kmer). 0:01:08.490 56M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:01:11.624 56M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:01:11.625 56M / 8G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:01:11.625 56M / 8G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:01:11.625 56M / 8G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:01:19.017 56M / 8G INFO Early tip clipping (early_simplification.hpp : 184) 5678987 34-mers were removed by early tip clipper 0:01:19.018 56M / 8G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:01:19.031 56M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:01:22.949 124M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1124153 sequences extracted 0:01:24.612 124M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:01:25.557 124M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 17 loops collected 0:01:26.377 372M / 8G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:01:26.377 372M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:01:26.377 372M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:01:28.029 384M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 10075600 bytes occupied (3.71113 bits per kmer). 0:01:28.066 468M / 8G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:02:57.624 464M / 8G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:03:00.030 464M / 8G INFO General (construction.cpp : 464) Processed 2248061 edges 0:03:00.230 344M / 8G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:03:00.236 344M / 8G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 52 0:03:00.236 344M / 8G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 135 0:03:00.236 344M / 8G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 137. Coverage mad: 29.652 0:03:00.236 344M / 8G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:03:00.465 344M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:03:01.043 344M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:03:02.947 344M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:03:07.025 344M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:03:10.583 344M / 8G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 138.855. Fitted coverage std. dev: 28.4761 0:03:10.587 344M / 8G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.860216 0:03:10.587 344M / 8G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 90 0:03:10.587 344M / 8G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 90 0:03:10.587 344M / 8G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 4988725 0:03:10.587 344M / 8G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 138.855 0:03:10.587 344M / 8G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 90 0:03:10.587 344M / 8G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:03:10.587 344M / 8G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:03:10.587 344M / 8G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:03:10.587 344M / 8G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 0:03:10.587 344M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:03:10.700 344M / 8G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:03:10.700 344M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial tip clipper 0:03:11.194 340M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial tip clipper triggered 19426 times 0:03:11.194 340M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial ec remover 0:03:25.153 364M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial ec remover triggered 319040 times 0:03:25.153 364M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial isolated edge remover 0:03:25.322 364M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial isolated edge remover triggered 17834 times 0:03:25.418 360M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:03:25.418 360M / 8G INFO General (simplification.cpp : 357) Graph simplification started 0:03:25.418 360M / 8G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:03:25.418 360M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:03:25.418 360M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:25.519 360M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3583 times 0:03:25.519 360M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:31.383 356M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 11288 times 0:03:31.383 356M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:34.433 304M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 59006 times 0:03:34.433 304M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:03:34.433 304M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:34.494 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 463 times 0:03:34.494 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:36.833 284M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 4377 times 0:03:36.833 284M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:37.209 232M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 7088 times 0:03:37.209 232M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:03:37.209 232M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:37.224 228M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 38 times 0:03:37.225 228M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:37.593 220M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 860 times 0:03:37.593 220M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:37.740 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2349 times 0:03:37.740 192M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:03:37.740 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:37.745 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 8 times 0:03:37.745 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:37.854 188M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 287 times 0:03:37.854 188M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:37.929 172M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1040 times 0:03:37.929 172M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:03:37.929 172M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:37.931 172M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3 times 0:03:37.931 172M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:37.970 172M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 133 times 0:03:37.970 172M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.008 156M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 608 times 0:03:38.008 156M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:03:38.008 156M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.009 156M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:03:38.009 156M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.025 156M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 59 times 0:03:38.025 156M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.066 148M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 434 times 0:03:38.066 148M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:03:38.066 148M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.067 148M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:03:38.067 148M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.078 148M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 44 times 0:03:38.078 148M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.108 140M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 261 times 0:03:38.108 140M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:03:38.108 140M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.109 140M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:03:38.109 140M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.116 140M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 24 times 0:03:38.116 140M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.122 132M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 175 times 0:03:38.122 132M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:03:38.122 132M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.123 132M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:03:38.123 132M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.128 128M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 21 times 0:03:38.128 128M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.144 128M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 129 times 0:03:38.144 128M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:03:38.144 128M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.144 128M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:03:38.144 128M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.148 128M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 11 times 0:03:38.148 128M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.162 128M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 109 times 0:03:38.162 128M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:03:38.162 128M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.164 128M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:03:38.164 128M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.180 124M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 15 times 0:03:38.180 124M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.187 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:03:38.187 120M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:03:38.187 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.187 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:03:38.187 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.187 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:03:38.187 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:03:38.187 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:03:38.187 120M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:03:38.188 120M / 8G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:03:38.188 120M / 8G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 0:03:38.188 120M / 8G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 0:03:38.188 120M / 8G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:03:38.188 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.190 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:03:38.190 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.203 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:03:38.203 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:38.205 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:03:38.205 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:03:38.217 120M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:03:38.217 120M / 8G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:03:38.227 120M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:03:38.265 100M / 8G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 1543 times 0:03:38.265 100M / 8G INFO General (simplification.cpp : 470) Counting average coverage 0:03:38.269 100M / 8G INFO General (simplification.cpp : 476) Average coverage = 249.206 0:03:38.269 100M / 8G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:03:38.269 100M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /tmp/183/output_dir//K33/simplified_contigs.fasta 0:03:38.365 100M / 8G INFO General (launch.hpp : 151) SPAdes finished 0:03:38.467 36M / 8G INFO General (main.cpp : 109) Assembling time: 0 hours 3 minutes 38 seconds == Running assembler: K55 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /tmp/183/output_dir/K55/configs/config.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 25 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from N/A, git revision N/A 0:00:00.001 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.001 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/tmp/183/output_dir/dataset.info) with K=55 0:00:00.001 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 8 0:00:00.001 4M / 4M INFO General (launch.hpp : 52) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 59) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 66) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO General (launch.hpp : 77) Will need read mapping, kmer mapper will be attached 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.002 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.003 4M / 4M INFO General (construction.cpp : 111) Max read length 100 0:00:00.003 4M / 4M INFO General (construction.cpp : 117) Average read length 99.9798 0:00:00.003 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.003 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. 0:00:00.003 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:00:00.004 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.0415 Gb 0:00:00.004 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:00:11.643 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 11184028 reads 0:00:22.893 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 22357057 reads 0:00:34.356 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 33540577 reads 0:00:40.627 6G / 6G INFO General (kmer_splitters.hpp : 289) Processed 39569116 reads 0:00:40.627 6G / 6G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:42.568 32M / 6G INFO General (kmer_splitters.hpp : 308) Used 39569116 reads 0:00:42.568 32M / 6G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:43.749 32M / 6G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 26314122 kmers in total. 0:00:43.750 32M / 6G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:44.287 32M / 6G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:44.287 32M / 6G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:44.287 32M / 6G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. 0:00:44.287 32M / 6G INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:00:44.287 32M / 6G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.04036 Gb 0:00:44.287 32M / 6G INFO General (kmer_splitters.hpp : 97) Using cell size of 262144 0:00:47.867 8G / 8G INFO General (kmer_splitters.hpp : 380) Processed 26314122 kmers 0:00:47.867 8G / 8G INFO General (kmer_splitters.hpp : 385) Used 26314122 kmers. 0:00:48.095 32M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:48.797 32M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 26284694 kmers in total. 0:00:48.797 32M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:49.333 32M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:50.736 32M / 8G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:51.277 32M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12196120 bytes occupied (3.71201 bits per kmer). 0:00:51.295 60M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:55.180 60M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:55.181 60M / 8G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:55.227 60M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:01:01.165 180M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1751231 sequences extracted 0:01:03.827 180M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:01:05.066 180M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:01:06.367 608M / 8G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:01:06.367 608M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:01:06.367 608M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:01:08.554 632M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12206048 bytes occupied (3.71087 bits per kmer). 0:01:08.602 736M / 8G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:02:12.694 736M / 8G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:02:16.827 736M / 8G INFO General (construction.cpp : 464) Processed 3502288 edges 0:02:17.072 572M / 8G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:02:17.076 576M / 8G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 33 0:02:17.076 572M / 8G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 88 0:02:17.076 572M / 8G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 90. Coverage mad: 25.2042 0:02:17.077 572M / 8G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:02:17.217 576M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:02:17.593 576M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:02:18.857 576M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:02:21.530 576M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:02:24.562 576M / 8G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 91.5693. Fitted coverage std. dev: 22.7255 0:02:24.565 576M / 8G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.688078 0:02:24.565 576M / 8G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 60 0:02:24.565 576M / 8G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 60 0:02:24.565 576M / 8G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 4861052 0:02:24.565 572M / 8G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 91.5693 0:02:24.565 572M / 8G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 60 0:02:24.565 572M / 8G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:02:24.565 572M / 8G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:02:24.565 572M / 8G INFO General (graph_pack.hpp : 101) Index refill 0:02:24.566 572M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:02:24.566 572M / 8G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. 0:02:24.566 572M / 8G INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:02:24.566 572M / 8G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.01839 Gb 0:02:24.566 572M / 8G INFO General (kmer_splitters.hpp : 97) Using cell size of 262144 0:02:26.435 8G / 8G INFO General (edge_index_builders.hpp : 77) Processed 3502288 edges 0:02:26.436 8G / 8G INFO General (edge_index_builders.hpp : 82) Used 3502288 sequences. 0:02:26.555 572M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:02:27.338 572M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 26314122 kmers in total. 0:02:27.338 572M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:02:27.881 572M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:02:29.452 580M / 8G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:02:30.027 580M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12209872 bytes occupied (3.71204 bits per kmer). 0:02:30.575 1G / 8G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:02:33.217 1G / 8G INFO General (edge_index.hpp : 92) Index refilled 0:02:33.217 1G / 8G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:02:36.474 1G / 8G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:03:27.474 1G / 8G INFO General (gap_closer.cpp : 138) Used 9863664 paired reads 0:03:27.474 1G / 8G INFO General (gap_closer.cpp : 140) Merging paired indices 0:03:28.896 1G / 8G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:03:37.014 1G / 8G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 291 gaps after checking 21218 candidates 0:03:37.395 1G / 8G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:03:37.525 576M / 8G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:03:37.525 576M / 8G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 0:03:37.525 576M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:03:37.745 576M / 8G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:03:37.745 576M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial tip clipper 0:03:54.059 612M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial tip clipper triggered 767277 times 0:03:54.059 612M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial ec remover 0:03:56.617 584M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial ec remover triggered 50220 times 0:03:56.617 584M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Initial isolated edge remover 0:03:57.097 548M / 8G INFO Simplification (parallel_processing.hpp : 167) Initial isolated edge remover triggered 58603 times 0:03:57.145 544M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:03:57.145 544M / 8G INFO General (simplification.cpp : 357) Graph simplification started 0:03:57.145 544M / 8G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:03:57.146 544M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:03:57.146 544M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:03:57.359 524M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 7769 times 0:03:57.359 524M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:05.555 536M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 8381 times 0:04:05.555 536M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:06.662 412M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 17017 times 0:04:06.662 412M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:04:06.662 412M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:06.722 404M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 817 times 0:04:06.722 404M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:08.974 396M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2013 times 0:04:08.974 396M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:09.368 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 5261 times 0:04:09.368 296M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:04:09.368 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:09.390 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 109 times 0:04:09.390 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:09.837 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 503 times 0:04:09.837 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:09.985 256M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1784 times 0:04:09.985 256M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:04:09.985 256M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:09.994 256M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 31 times 0:04:09.994 256M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.134 252M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 184 times 0:04:10.134 252M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.215 236M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 829 times 0:04:10.215 236M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:04:10.215 236M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.218 236M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 12 times 0:04:10.218 236M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.270 228M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 94 times 0:04:10.270 228M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.304 216M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 485 times 0:04:10.304 216M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:04:10.304 216M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.305 216M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 6 times 0:04:10.305 216M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.350 216M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 57 times 0:04:10.350 216M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.364 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 252 times 0:04:10.364 212M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:04:10.364 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.365 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 5 times 0:04:10.365 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.389 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 18 times 0:04:10.389 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.407 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 207 times 0:04:10.407 212M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:04:10.407 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.407 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 5 times 0:04:10.407 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.426 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 16 times 0:04:10.426 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.440 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 115 times 0:04:10.440 212M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:04:10.440 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.440 212M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:04:10.440 212M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.445 208M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 7 times 0:04:10.445 208M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.453 208M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 120 times 0:04:10.453 208M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:04:10.453 208M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.453 208M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2 times 0:04:10.453 208M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.458 208M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 11 times 0:04:10.458 208M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.463 196M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 89 times 0:04:10.463 196M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:04:10.463 196M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.464 196M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 6 times 0:04:10.464 196M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.474 196M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 7 times 0:04:10.474 196M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.480 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:04:10.480 192M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:04:10.480 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:10.480 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:04:10.480 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:10.480 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:04:10.480 192M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:04:10.480 192M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:04:10.480 192M / 8G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:04:10.480 192M / 8G INFO General (graph_pack.hpp : 101) Index refill 0:04:10.480 192M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:04:10.480 192M / 8G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. 0:04:10.480 192M / 8G INFO General (file_limit.hpp : 32) Open file limit set to 1048576 0:04:10.480 192M / 8G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.03385 Gb 0:04:10.480 192M / 8G INFO General (kmer_splitters.hpp : 97) Using cell size of 262144 0:04:10.747 8G / 8G INFO General (edge_index_builders.hpp : 77) Processed 7168 edges 0:04:10.748 8G / 8G INFO General (edge_index_builders.hpp : 82) Used 7168 sequences. 0:04:10.776 180M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:04:11.043 180M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 5265070 kmers in total. 0:04:11.044 180M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:04:11.140 180M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:04:11.417 200M / 8G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:04:11.520 200M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 2449592 bytes occupied (3.72203 bits per kmer). 0:04:11.742 324M / 8G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:04:12.072 324M / 8G INFO General (edge_index.hpp : 92) Index refilled 0:04:12.073 324M / 8G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:04:12.079 324M / 8G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:04:34.372 328M / 8G INFO General (gap_closer.cpp : 138) Used 9863664 paired reads 0:04:34.372 328M / 8G INFO General (gap_closer.cpp : 140) Merging paired indices 0:04:34.374 328M / 8G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:04:34.384 328M / 8G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 0 gaps after checking 56 candidates 0:04:34.399 328M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:04:34.400 328M / 8G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:04:34.400 328M / 8G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 0:04:34.400 328M / 8G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 0:04:34.400 328M / 8G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:04:34.400 328M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:34.414 328M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:04:34.415 328M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:34.439 328M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:04:34.440 328M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:04:34.448 328M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:04:34.448 328M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:04:34.457 328M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:04:34.457 328M / 8G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:04:34.464 328M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:04:34.511 304M / 8G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 265 times 0:04:34.511 304M / 8G INFO General (simplification.cpp : 470) Counting average coverage 0:04:34.515 304M / 8G INFO General (simplification.cpp : 476) Average coverage = 164.095 0:04:34.515 304M / 8G INFO StageManager (stage.cpp : 132) STAGE == Mismatch Correction 0:04:34.515 304M / 8G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 1288172 kmers to process 0:04:35.606 304M / 8G INFO General (graph_pack.hpp : 111) Normalizing done 0:05:32.154 352M / 8G INFO General (mismatch_shall_not_pass.hp: 189) Finished collecting potential mismatches positions 0:05:32.413 308M / 8G INFO General (mismatch_shall_not_pass.hp: 290) All edges processed 0:05:32.428 304M / 8G INFO General (mismatch_correction.cpp : 27) Corrected 2 nucleotides 0:05:32.428 304M / 8G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:05:32.428 304M / 8G INFO General (contig_output_stage.cpp : 45) Writing GFA to /tmp/183/output_dir//K55/assembly_graph_with_scaffolds.gfa 0:05:32.499 304M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /tmp/183/output_dir//K55/before_rr.fasta 0:05:32.583 304M / 8G INFO General (contig_output_stage.cpp : 56) Outputting FastG graph to /tmp/183/output_dir//K55/assembly_graph.fastg 0:05:32.875 304M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /tmp/183/output_dir//K55/final_contigs.fasta 0:05:32.959 304M / 8G INFO StageManager (stage.cpp : 132) STAGE == Paired Information Counting 0:05:32.976 304M / 8G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 1288312 kmers to process 0:05:34.053 304M / 8G INFO General (graph_pack.hpp : 111) Normalizing done 0:05:34.057 304M / 8G INFO General (pair_info_count.cpp : 323) Min edge length for estimation: 31236 0:05:34.057 304M / 8G INFO General (pair_info_count.cpp : 334) Estimating insert size for library #0 0:05:34.057 304M / 8G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 0:05:34.120 448M / 8G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:05:38.493 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 0:05:38.559 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 0:05:38.630 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 0:05:38.694 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 0:05:38.762 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 0:05:38.833 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 0:05:43.095 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 0:05:47.788 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 0:06:01.434 448M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 0:06:03.267 448M / 8G INFO General (sequence_mapper_notifier.h: 98) Total 9863664 reads processed 0:06:03.580 448M / 8G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 0:06:03.580 448M / 8G INFO General (pair_info_count.cpp : 213) 2773500 paired reads (28.1184% of all) aligned to long edges 0:06:03.609 304M / 8G INFO General (pair_info_count.cpp : 357) Insert size = 297.912, deviation = 141.961, left quantile = 146, right quantile = 488, read length = 100 0:06:03.700 496M / 8G INFO General (pair_info_count.cpp : 374) Filtering data for library #0 0:06:03.700 496M / 8G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:06:09.209 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 0:06:09.255 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 0:06:09.259 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 0:06:09.261 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 0:06:09.263 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 0:06:09.283 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 0:06:14.789 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 0:06:20.452 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 0:06:37.462 496M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 0:06:38.785 496M / 8G INFO General (sequence_mapper_notifier.h: 98) Total 9863664 reads processed 0:06:38.785 496M / 8G INFO General (pair_info_count.cpp : 386) Mapping library #0 0:06:38.785 496M / 8G INFO General (pair_info_count.cpp : 388) Mapping paired reads (takes a while) 0:06:38.785 496M / 8G INFO General (pair_info_count.cpp : 289) Left insert size quantile 146, right insert size quantile 488, filtering threshold 2, rounding threshold 0 0:06:38.800 508M / 8G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:06:46.261 560M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 0:06:46.320 560M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 0:06:46.324 560M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 0:06:46.333 560M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 0:06:46.358 560M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 0:06:46.371 560M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 0:06:54.129 564M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 0:07:02.051 564M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 0:07:26.087 596M / 8G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 0:07:27.598 596M / 8G INFO General (sequence_mapper_notifier.h: 98) Total 9863664 reads processed 0:07:27.653 392M / 8G INFO StageManager (stage.cpp : 132) STAGE == Distance Estimation 0:07:27.653 392M / 8G INFO General (distance_estimation.cpp : 173) Processing library #0 0:07:27.653 392M / 8G INFO General (distance_estimation.cpp : 149) Weight Filter Done 0:07:27.653 392M / 8G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 0:07:29.318 392M / 8G INFO General (distance_estimation.cpp : 34) Filtering info 0:07:29.318 392M / 8G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 189285 0:07:29.408 400M / 8G INFO General (pair_info_filters.hpp : 263) Done filtering 0:07:29.409 392M / 8G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 0:07:29.471 392M / 8G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 0:07:29.471 392M / 8G INFO General (distance_estimation.cpp : 160) Improving paired information 0:07:31.619 396M / 8G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 8192; contradictional = 2278 0:07:33.479 396M / 8G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 711; contradictional = 42 0:07:33.479 396M / 8G INFO General (distance_estimation.cpp : 103) Filling scaffolding index 0:07:33.479 396M / 8G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator 0:07:37.480 396M / 8G INFO General (distance_estimation.cpp : 34) Filtering info 0:07:37.480 396M / 8G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 153189 0:07:37.547 404M / 8G INFO General (pair_info_filters.hpp : 263) Done filtering 0:07:37.548 396M / 8G INFO General (distance_estimation.cpp : 182) Clearing raw paired index 0:07:37.713 336M / 8G INFO StageManager (stage.cpp : 132) STAGE == Repeat Resolving 0:07:37.713 336M / 8G INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving 0:07:37.713 336M / 8G INFO General (launcher.cpp : 481) ExSPAnder repeat resolving tool started 0:07:37.742 348M / 8G INFO General (launcher.cpp : 392) Creating main extenders, unique edge length = 2000 0:07:37.743 348M / 8G INFO General (extenders_logic.cpp : 278) Estimated coverage of library #0 is 164.095 0:07:37.744 348M / 8G INFO General (extenders_logic.cpp : 278) Estimated coverage of library #0 is 164.095 0:07:37.748 348M / 8G INFO General (extenders_logic.cpp : 475) Using 1 paired-end library 0:07:37.748 348M / 8G INFO General (extenders_logic.cpp : 476) Using 1 paired-end scaffolding library 0:07:37.748 348M / 8G INFO General (extenders_logic.cpp : 477) Using 0 single read libraries 0:07:37.748 348M / 8G INFO General (launcher.cpp : 420) Total number of extenders is 3 0:07:37.748 348M / 8G INFO General (path_extender.hpp : 885) Processed 0 paths from 3273 (0%) 0:07:39.256 352M / 8G INFO General (path_extender.hpp : 883) Processed 128 paths from 3273 (3%) 0:07:40.144 356M / 8G INFO General (path_extender.hpp : 883) Processed 256 paths from 3273 (7%) 0:07:40.379 356M / 8G INFO General (path_extender.hpp : 885) Processed 328 paths from 3273 (10%) 0:07:40.725 360M / 8G INFO General (path_extender.hpp : 883) Processed 512 paths from 3273 (15%) 0:07:40.827 360M / 8G INFO General (path_extender.hpp : 885) Processed 656 paths from 3273 (20%) 0:07:40.946 364M / 8G INFO General (path_extender.hpp : 885) Processed 984 paths from 3273 (30%) 0:07:41.023 364M / 8G INFO General (path_extender.hpp : 883) Processed 1024 paths from 3273 (31%) 0:07:41.757 368M / 8G INFO General (path_extender.hpp : 885) Processed 1312 paths from 3273 (40%) 0:07:43.379 372M / 8G INFO General (path_extender.hpp : 885) Processed 1640 paths from 3273 (50%) 0:07:44.459 376M / 8G INFO General (path_extender.hpp : 885) Processed 1968 paths from 3273 (60%) 0:07:44.760 376M / 8G INFO General (path_extender.hpp : 883) Processed 2048 paths from 3273 (62%) 0:07:44.912 376M / 8G INFO General (path_extender.hpp : 885) Processed 2296 paths from 3273 (70%) 0:07:45.307 380M / 8G INFO General (path_extender.hpp : 885) Processed 2624 paths from 3273 (80%) 0:07:45.480 380M / 8G INFO General (path_extender.hpp : 885) Processed 2952 paths from 3273 (90%) 0:07:45.518 380M / 8G INFO General (launcher.cpp : 234) Finalizing paths 0:07:45.518 380M / 8G INFO General (launcher.cpp : 236) Deduplicating paths 0:07:46.109 380M / 8G INFO General (launcher.cpp : 240) Paths deduplicated 0:07:46.109 380M / 8G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 0:07:46.109 380M / 8G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths 0:07:46.110 380M / 8G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 0:07:46.110 380M / 8G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 0:07:46.729 380M / 8G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps 0:07:47.364 380M / 8G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 0:07:47.386 380M / 8G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 0:07:47.424 376M / 8G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 0:07:47.435 376M / 8G INFO General (launcher.cpp : 257) Paths finalized 0:07:47.435 376M / 8G INFO General (launcher.cpp : 427) Closing gaps in paths 0:07:47.448 380M / 8G INFO General (launcher.cpp : 455) Gap closing completed 0:07:47.453 380M / 8G INFO General (launcher.cpp : 286) Traversing tandem repeats 0:07:47.483 380M / 8G INFO General (launcher.cpp : 296) Traversed 9 loops 0:07:47.484 380M / 8G INFO General (launcher.cpp : 234) Finalizing paths 0:07:47.484 380M / 8G INFO General (launcher.cpp : 236) Deduplicating paths 0:07:47.486 380M / 8G INFO General (launcher.cpp : 240) Paths deduplicated 0:07:47.486 380M / 8G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 0:07:47.486 380M / 8G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths 0:07:47.488 380M / 8G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 0:07:47.488 380M / 8G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 0:07:47.494 380M / 8G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps 0:07:47.501 380M / 8G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 0:07:47.501 380M / 8G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 0:07:47.504 380M / 8G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 0:07:47.510 380M / 8G INFO General (launcher.cpp : 257) Paths finalized 0:07:47.510 380M / 8G INFO General (launcher.cpp : 534) ExSPAnder repeat resolving tool finished 0:07:47.618 348M / 8G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:07:47.618 348M / 8G INFO General (contig_output_stage.cpp : 45) Writing GFA to /tmp/183/output_dir//K55/assembly_graph_with_scaffolds.gfa 0:07:47.691 348M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /tmp/183/output_dir//K55/before_rr.fasta 0:07:47.777 344M / 8G INFO General (contig_output_stage.cpp : 56) Outputting FastG graph to /tmp/183/output_dir//K55/assembly_graph.fastg 0:07:48.091 352M / 8G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /tmp/183/output_dir//K55/final_contigs.paths 0:07:48.238 344M / 8G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /tmp/183/output_dir//K55/scaffolds.paths 0:07:48.371 348M / 8G INFO General (launch.hpp : 151) SPAdes finished 0:07:49.163 36M / 8G INFO General (main.cpp : 109) Assembling time: 0 hours 7 minutes 49 seconds ===== Assembling finished. Used k-mer sizes: 21, 33, 55 * Corrected reads are in /tmp/183/output_dir/corrected/ * Assembled contigs are in /tmp/183/output_dir/contigs.fasta * Assembled scaffolds are in /tmp/183/output_dir/scaffolds.fasta * Paths in the assembly graph corresponding to the contigs are in /tmp/183/output_dir/contigs.paths * Paths in the assembly graph corresponding to the scaffolds are in /tmp/183/output_dir/scaffolds.paths * Assembly graph is in /tmp/183/output_dir/assembly_graph.fastg * Assembly graph in GFA format is in /tmp/183/output_dir/assembly_graph_with_scaffolds.gfa ======= SPAdes pipeline finished. SPAdes log can be found here: /tmp/183/output_dir/spades.log Thank you for using SPAdes! + post_processing + '[' 1 = 1 ']' + '[' 'docker run -v $PWD:$PWD -w $PWD -u root -i --rm ' = 'docker run -v $PWD:$PWD -w $PWD -u root -i --rm ' ']' + docker run -v /tmp/183:/tmp/183 -w /tmp/183 -u root -i --rm centos:centos6 chmod -R a=rXw . + echo 0 + exit