search

ablab / spades

SPAdes Genome Assembler
http://ablab.github.io/spades/
Other
737 stars 134 forks source link

Assertion `index_.size() != 0' failed | metaSPAdes failed towards the end of a run #267

Closed jolespin closed 5 years ago

jolespin commented 5 years ago

I'm not sure what happened but metaSPAdes failed towards the end of my run. Do you have an idea on what might be happening?

Collapsed metaSPAdes output

``` System information: SPAdes version: 3.13.0 Python version: 2.7.15 OS: Linux-2.6.32-696.el6.x86_64-x86_64-with-centos-6.4-Final Output dir: /home/jespinoz/metaspades_output Mode: read error correction and assembling Debug mode is turned OFF Dataset parameters: Metagenomic mode Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/home/jespinoz/bbmap_output/mapped_R1.fq'] right reads: ['/home/jespinoz/bbmap_output/mapped_R2.fq'] 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: [21, 33, 55] 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: /home/jespinoz/tmp Threads: 32 Memory limit (in Gb): 250 ======= SPAdes pipeline started. Log can be found here: /home/jespinoz/metaspades_output/spades.log ===== Read error correction started. == Running read error correction tool: /usr/local/devel/ANNOTATION/jespinoz/anaconda/envs/mage_env/share/spades-3.13.0-0/bin/spades-hammer /home/jespinoz/metaspades_output/corrected/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 75) Starting BayesHammer, built from refs/heads/spades_3.13.0, git revision 8ea46659e9b2aca35444a808db550ac333006f8b 0:00:00.000 4M / 4M INFO General (main.cpp : 76) Loading config from /home/jespinoz/metaspades_output/corrected/configs/config.info 0:00:00.002 4M / 4M INFO General (main.cpp : 78) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.002 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.002 4M / 4M INFO General (main.cpp : 86) Trying to determine PHRED offset 0:00:00.003 4M / 4M INFO General (main.cpp : 92) Determined value is 33 0:00:00.003 4M / 4M INFO General (hammer_tools.cpp : 36) Hamming graph threshold tau=1, k=21, subkmer positions = [ 0 10 ] 0:00:00.003 4M / 4M INFO General (main.cpp : 113) Size of aux. kmer data 24 bytes === ITERATION 0 begins === 0:00:00.003 4M / 4M INFO K-mer Counting (kmer_data.cpp : 280) Estimating k-mer count 0:00:00.414 516M / 516M INFO K-mer Counting (kmer_data.cpp : 285) Processing /home/jespinoz/bbmap_output/mapped_R1.fq 0:00:00.443 640M / 640M INFO K-mer Counting (kmer_data.cpp : 285) Processing /home/jespinoz/bbmap_output/mapped_R2.fq 0:00:00.475 640M / 640M INFO K-mer Counting (kmer_data.cpp : 299) Total 3716 reads processed 0:00:03.018 128M / 640M INFO K-mer Counting (kmer_data.cpp : 311) Filtering singleton k-mers 38 8 0 nslots: 1073741824 bits per slot: 8 range: 0000004000000000 0:00:03.018 1G / 1G INFO K-mer Counting (kmer_data.cpp : 317) Processing /home/jespinoz/bbmap_output/mapped_R1.fq 0:00:03.443 1G / 1G INFO K-mer Counting (kmer_data.cpp : 317) Processing /home/jespinoz/bbmap_output/mapped_R2.fq 0:00:03.790 1G / 1G INFO K-mer Counting (kmer_data.cpp : 331) Total 3716 reads processed 0:00:03.796 1G / 1G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:03.796 1G / 1G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:00:03.800 1G / 1G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:03.800 1G / 1G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58964 Gb 0:00:03.800 1G / 1G INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:08.365 19G / 19G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /home/jespinoz/bbmap_output/mapped_R1.fq 0:00:13.278 19G / 19G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /home/jespinoz/bbmap_output/mapped_R2.fq 0:00:15.431 19G / 19G INFO K-mer Splitting (kmer_data.cpp : 112) Total 3716 reads processed 0:00:17.525 1G / 19G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:21.535 1G / 19G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 59762 kmers in total. 0:00:21.536 1G / 19G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:23.723 1G / 19G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:23.763 1G / 19G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:23.836 1G / 19G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 36608 bytes occupied (4.90051 bits per kmer). 0:00:23.850 128M / 19G INFO K-mer Counting (kmer_data.cpp : 356) Arranging kmers in hash map order 0:00:23.868 132M / 19G INFO General (main.cpp : 148) Clustering Hamming graph. 0:00:23.895 132M / 19G INFO General (main.cpp : 155) Extracting clusters 0:00:23.939 128M / 19G INFO General (main.cpp : 167) Clustering done. Total clusters: 50824 0:00:23.939 128M / 19G INFO K-mer Counting (kmer_data.cpp : 376) Collecting K-mer information, this takes a while. 0:00:23.939 132M / 19G INFO K-mer Counting (kmer_data.cpp : 382) Processing /home/jespinoz/bbmap_output/mapped_R1.fq 0:00:23.954 132M / 19G INFO K-mer Counting (kmer_data.cpp : 382) Processing /home/jespinoz/bbmap_output/mapped_R2.fq 0:00:23.969 132M / 19G INFO K-mer Counting (kmer_data.cpp : 389) Collection done, postprocessing. 0:00:23.970 132M / 19G INFO K-mer Counting (kmer_data.cpp : 403) There are 59762 kmers in total. Among them 4 (0.00669322%) are singletons. 0:00:23.970 132M / 19G INFO General (main.cpp : 173) Subclustering Hamming graph 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 649) Subclustering done. Total 0 non-read kmers were generated. 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 650) Subclustering statistics: 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 651) Total singleton hamming clusters: 44534. Among them 43184 (96.9686%) are good 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 652) Total singleton subclusters: 1684. Among them 1684 (100%) are good 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 653) Total non-singleton subcluster centers: 6038. Among them 6019 (99.6853%) are good 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 654) Average size of non-trivial subcluster: 2.52203 kmers 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 655) Average number of sub-clusters per non-singleton cluster: 1.22766 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 656) Total solid k-mers: 50887 0:00:24.033 132M / 19G INFO Hamming Subclustering (kmer_cluster.cpp : 657) Substitution probabilities: [4,4]((0.944327,0.0120306,0.0315111,0.0121313),(0.00844963,0.948795,0.00705405,0.0357016),(0.029751,0.00691468,0.953638,0.00969586),(0.0101293,0.0256541,0.0102311,0.953986)) 0:00:24.037 132M / 19G INFO General (main.cpp : 178) Finished clustering. 0:00:24.037 132M / 19G INFO General (main.cpp : 197) Starting solid k-mers expansion in 32 threads. 0:00:24.063 132M / 19G INFO General (main.cpp : 218) Solid k-mers iteration 0 produced 2015 new k-mers. 0:00:24.090 132M / 19G INFO General (main.cpp : 218) Solid k-mers iteration 1 produced 54 new k-mers. 0:00:24.118 132M / 19G INFO General (main.cpp : 218) Solid k-mers iteration 2 produced 0 new k-mers. 0:00:24.118 132M / 19G INFO General (main.cpp : 222) Solid k-mers finalized 0:00:24.119 132M / 19G INFO General (hammer_tools.cpp : 220) Starting read correction in 32 threads. 0:00:24.119 132M / 19G INFO General (hammer_tools.cpp : 233) Correcting pair of reads: /home/jespinoz/bbmap_output/mapped_R1.fq and /home/jespinoz/bbmap_output/mapped_R2.fq 0:00:24.266 380M / 19G INFO General (hammer_tools.cpp : 168) Prepared batch 0 of 1858 reads. 0:00:24.281 380M / 19G INFO General (hammer_tools.cpp : 175) Processed batch 0 0:00:24.287 380M / 19G INFO General (hammer_tools.cpp : 185) Written batch 0 0:00:24.455 132M / 19G INFO General (hammer_tools.cpp : 274) Correction done. Changed 605 bases in 351 reads. 0:00:24.455 132M / 19G INFO General (hammer_tools.cpp : 275) Failed to correct 83 bases out of 541959. 0:00:24.456 128M / 19G INFO General (main.cpp : 255) Saving corrected dataset description to /home/jespinoz/metaspades_output/corrected/corrected.yaml 0:00:24.461 128M / 19G INFO General (main.cpp : 262) All done. Exiting. == Compressing corrected reads (with pigz) == Dataset description file was created: /home/jespinoz/metaspades_output/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 /home/jespinoz/metaspades_output/K21/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K21/configs/mda_mode.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K21/configs/meta_mode.info 0:00:00.001 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from refs/heads/spades_3.13.0, git revision 8ea46659e9b2aca35444a808db550ac333006f8b 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 (/home/jespinoz/metaspades_output/dataset.info) with K=21 0:00:00.001 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.001 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.007 4M / 4M INFO General (read_converter.hpp : 77) Converting reads to binary format for library #0 (takes a while) 0:00:00.007 4M / 4M INFO General (read_converter.hpp : 78) Converting paired reads 0:00:00.196 68M / 68M INFO General (binary_converter.hpp : 117) 68 reads written 0:00:00.209 4M / 68M INFO General (read_converter.hpp : 87) Converting single reads 0:00:00.473 132M / 136M INFO General (binary_converter.hpp : 117) 1482 reads written 0:00:00.475 4M / 136M INFO General (read_converter.hpp : 95) Converting merged reads 0:00:00.720 132M / 136M INFO General (binary_converter.hpp : 117) 0 reads written 0:00:01.021 4M / 136M INFO General (construction.cpp : 111) Max read length 151 0:00:01.021 4M / 136M INFO General (construction.cpp : 117) Average read length 145.932 0:00:01.021 4M / 136M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:01.026 4M / 136M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 1024 files using 32 threads. This might take a while. 0:00:01.030 4M / 136M INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:01.030 4M / 136M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60413 Gb 0:00:01.030 4M / 136M INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:00:13.976 17G / 17G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:15.823 132M / 17G INFO General (kmer_splitters.hpp : 308) Used 3236 reads 0:00:15.823 132M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:25.093 132M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 54963 kmers in total. 0:00:25.093 132M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:29.337 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:29.339 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:29.339 128M / 17G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:00:29.342 128M / 17G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:29.342 128M / 17G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60286 Gb 0:00:29.342 128M / 17G INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:38.659 17G / 17G INFO General (kmer_splitters.hpp : 380) Processed 54963 kmers 0:00:38.659 17G / 17G INFO General (kmer_splitters.hpp : 385) Used 54963 kmers. 0:00:40.781 128M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:46.330 128M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 54771 kmers in total. 0:00:46.330 128M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:48.621 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:48.669 128M / 17G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:48.731 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 34216 bytes occupied (4.99768 bits per kmer). 0:00:48.732 128M / 17G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:48.747 128M / 17G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:48.751 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:00:48.751 128M / 17G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:00:48.751 128M / 17G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:00:48.773 128M / 17G INFO Early tip clipping (early_simplification.hpp : 184) 8269 22-mers were removed by early tip clipper 0:00:48.774 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:48.780 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:48.785 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1104 sequences extracted 0:00:48.789 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:48.798 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 3 loops collected 0:00:48.822 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:48.822 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:48.823 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:48.963 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 43496 bytes occupied (6.33095 bits per kmer). 0:00:48.964 128M / 17G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:49.007 128M / 17G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:49.013 128M / 17G INFO General (construction.cpp : 464) Processed 2213 edges 0:00:49.028 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:49.028 128M / 17G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:49.028 128M / 17G INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:00:49.028 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:49.030 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:49.031 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial tip clipper 0:00:49.035 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial tip clipper triggered 12 times 0:00:49.036 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial ec remover 0:00:49.043 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial ec remover triggered 109 times 0:00:49.043 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial isolated edge remover 0:00:49.045 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial isolated edge remover triggered 31 times 0:00:49.045 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:49.046 128M / 17G INFO General (simplification.cpp : 357) Graph simplification started 0:00:49.046 128M / 17G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:49.046 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:49.047 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:49.047 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 21 times 0:00:49.048 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:49.057 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 164 times 0:00:49.057 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:49.058 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:49.058 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:49.058 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:49.059 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 8 times 0:00:49.059 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:49.059 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:49.060 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:49.060 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 8 times 0:00:49.060 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:49.060 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:49.060 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:49.060 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:49.060 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 8 times 0:00:49.060 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:49.061 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3 times 0:00:49.061 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:49.061 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:49.063 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:49.063 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:49.065 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 5 times 0:00:49.065 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:49.065 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:49.066 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:49.066 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:49.066 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:49.067 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:49.067 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:49.067 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:49.067 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:49.067 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:49.067 128M / 17G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:49.067 128M / 17G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:49.067 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:00:49.067 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 0:00:49.067 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Disconnecting edges with relatively low coverage 0:00:49.068 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Disconnecting edges with relatively low coverage triggered 0 times 0:00:49.068 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex tip clipper 0:00:49.068 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex tip clipper triggered 1 times 0:00:49.068 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:00:49.071 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 7 times 0:00:49.071 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:49.071 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:49.071 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:00:49.071 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 0:00:49.071 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Thorn remover (meta) 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Thorn remover (meta) triggered 0 times 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Disconnecting edges with relatively low coverage 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Disconnecting edges with relatively low coverage triggered 0 times 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex tip clipper 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex tip clipper triggered 0 times 0:00:49.072 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:00:49.076 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 0:00:49.076 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:49.080 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:49.080 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:00:49.084 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 0:00:49.084 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:49.086 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:49.086 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Thorn remover (meta) 0:00:49.086 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Thorn remover (meta) triggered 0 times 0:00:49.086 128M / 17G INFO General (simplification.cpp : 326) Running Hidden EC remover (meta) 0:00:49.086 128M / 17G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:49.086 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:00:49.086 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 2 times 0:00:49.086 128M / 17G INFO General (simplification.cpp : 470) Counting average coverage 0:00:49.086 128M / 17G INFO General (simplification.cpp : 476) Average coverage = 5.97889 0:00:49.086 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:49.086 128M / 17G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/jespinoz/metaspades_output//K21/assembly_graph_with_scaffolds.gfa 0:00:49.094 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K21/before_rr.fasta 0:00:49.099 128M / 17G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/jespinoz/metaspades_output//K21/assembly_graph.fastg 0:00:49.105 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K21/simplified_contigs.fasta 0:00:49.110 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K21/final_contigs.fasta 0:00:49.119 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:49.119 128M / 17G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/jespinoz/metaspades_output//K21/assembly_graph_with_scaffolds.gfa 0:00:49.123 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K21/before_rr.fasta 0:00:49.140 128M / 17G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/jespinoz/metaspades_output//K21/assembly_graph.fastg 0:00:49.149 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K21/simplified_contigs.fasta 0:00:49.159 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K21/final_contigs.fasta 0:00:49.172 128M / 17G INFO General (launch.hpp : 149) SPAdes finished 0:00:49.172 128M / 17G INFO General (main.cpp : 109) Assembling time: 0 hours 0 minutes 49 seconds Max read length detected as 151 == Running assembler: K33 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K33/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K33/configs/mda_mode.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K33/configs/meta_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from refs/heads/spades_3.13.0, git revision 8ea46659e9b2aca35444a808db550ac333006f8b 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 (/home/jespinoz/metaspades_output/dataset.info) with K=33 0:00:00.001 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.001 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.005 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.107 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.107 4M / 4M INFO General (construction.cpp : 117) Average read length 145.932 0:00:00.107 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.111 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 1024 files using 32 threads. This might take a while. 0:00:00.116 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:00.116 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60413 Gb 0:00:00.116 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 32768 0:00:12.698 17G / 17G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:19.342 132M / 17G INFO General (kmer_splitters.hpp : 308) Used 3236 reads 0:00:19.342 132M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:29.057 132M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 55918 kmers in total. 0:00:29.057 132M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:33.371 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:33.373 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:33.374 128M / 17G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:00:33.377 128M / 17G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:33.377 128M / 17G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60286 Gb 0:00:33.377 128M / 17G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:00:44.382 17G / 17G INFO General (kmer_splitters.hpp : 380) Processed 55918 kmers 0:00:44.382 17G / 17G INFO General (kmer_splitters.hpp : 385) Used 55918 kmers. 0:00:46.502 128M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:52.084 128M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 55917 kmers in total. 0:00:52.084 128M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:55.050 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:55.103 128M / 17G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:55.213 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 34768 bytes occupied (4.97423 bits per kmer). 0:00:55.213 128M / 17G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:55.236 128M / 17G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:55.242 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:00:55.242 128M / 17G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:00:55.242 128M / 17G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:00:55.275 128M / 17G INFO Early tip clipping (early_simplification.hpp : 184) 9984 34-mers were removed by early tip clipper 0:00:55.275 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:55.283 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:55.287 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 688 sequences extracted 0:00:55.292 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:55.301 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 2 loops collected 0:00:55.317 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:55.317 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:55.318 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:55.496 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 43872 bytes occupied (6.27662 bits per kmer). 0:00:55.496 128M / 17G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:55.562 128M / 17G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:55.568 128M / 17G INFO General (construction.cpp : 464) Processed 1380 edges 0:00:55.578 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:55.578 128M / 17G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:55.578 128M / 17G INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:00:55.578 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:55.581 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:55.581 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial tip clipper 0:00:55.585 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial tip clipper triggered 19 times 0:00:55.585 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial ec remover 0:00:55.588 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial ec remover triggered 44 times 0:00:55.588 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial isolated edge remover 0:00:55.589 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial isolated edge remover triggered 61 times 0:00:55.589 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:55.590 128M / 17G INFO General (simplification.cpp : 357) Graph simplification started 0:00:55.590 128M / 17G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:55.590 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:55.590 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.591 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 27 times 0:00:55.592 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.596 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 84 times 0:00:55.596 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:55.597 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:55.597 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:55.598 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.598 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 4 times 0:00:55.598 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.599 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2 times 0:00:55.599 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:55.599 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1 times 0:00:55.599 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:55.599 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.600 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2 times 0:00:55.600 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.600 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:55.600 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:55.600 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1 times 0:00:55.600 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:55.600 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.603 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:55.603 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.604 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3 times 0:00:55.605 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:55.605 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:55.605 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:55.606 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.606 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:55.606 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:55.607 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:55.607 128M / 17G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:55.607 128M / 17G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 1 times 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Disconnecting edges with relatively low coverage 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Disconnecting edges with relatively low coverage triggered 0 times 0:00:55.607 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex tip clipper 0:00:55.608 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex tip clipper triggered 2 times 0:00:55.608 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 2 times 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:00:55.610 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Thorn remover (meta) 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Thorn remover (meta) triggered 0 times 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Disconnecting edges with relatively low coverage 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Disconnecting edges with relatively low coverage triggered 0 times 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex tip clipper 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex tip clipper triggered 0 times 0:00:55.611 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:00:55.612 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 0:00:55.612 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Thorn remover (meta) 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Thorn remover (meta) triggered 0 times 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Disconnecting edges with relatively low coverage 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Disconnecting edges with relatively low coverage triggered 0 times 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex tip clipper 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex tip clipper triggered 0 times 0:00:55.613 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Thorn remover (meta) 0:00:55.617 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Thorn remover (meta) triggered 0 times 0:00:55.617 128M / 17G INFO General (simplification.cpp : 326) Running Hidden EC remover (meta) 0:00:55.621 128M / 17G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:55.622 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:00:55.626 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 1 times 0:00:55.626 128M / 17G INFO General (simplification.cpp : 470) Counting average coverage 0:00:55.626 128M / 17G INFO General (simplification.cpp : 476) Average coverage = 5.09591 0:00:55.626 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:55.626 128M / 17G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/jespinoz/metaspades_output//K33/assembly_graph_with_scaffolds.gfa 0:00:55.630 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K33/before_rr.fasta 0:00:55.635 128M / 17G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/jespinoz/metaspades_output//K33/assembly_graph.fastg 0:00:55.644 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K33/simplified_contigs.fasta 0:00:55.650 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K33/final_contigs.fasta 0:00:55.659 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:55.659 128M / 17G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/jespinoz/metaspades_output//K33/assembly_graph_with_scaffolds.gfa 0:00:55.664 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K33/before_rr.fasta 0:00:55.671 128M / 17G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/jespinoz/metaspades_output//K33/assembly_graph.fastg 0:00:55.681 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K33/simplified_contigs.fasta 0:00:55.688 128M / 17G INFO General (contig_output.hpp : 22) Outputting contigs to /home/jespinoz/metaspades_output//K33/final_contigs.fasta 0:00:55.703 128M / 17G INFO General (launch.hpp : 149) SPAdes finished 0:00:55.704 128M / 17G INFO General (main.cpp : 109) Assembling time: 0 hours 0 minutes 55 seconds == Running assembler: K55 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K55/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K55/configs/mda_mode.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/jespinoz/metaspades_output/K55/configs/meta_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from refs/heads/spades_3.13.0, git revision 8ea46659e9b2aca35444a808db550ac333006f8b 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 (/home/jespinoz/metaspades_output/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): 32 0:00:00.001 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 1 0:00:00.001 4M / 4M INFO General (launch.hpp : 76) 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.005 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.106 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.106 4M / 4M INFO General (construction.cpp : 117) Average read length 145.932 0:00:00.106 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.109 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 1024 files using 32 threads. This might take a while. 0:00:00.113 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:00.113 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60413 Gb 0:00:00.113 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 32768 0:00:13.788 17G / 17G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:20.253 132M / 17G INFO General (kmer_splitters.hpp : 308) Used 3236 reads 0:00:20.253 132M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:30.001 132M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 54024 kmers in total. 0:00:30.001 132M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:34.576 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:34.579 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:34.579 128M / 17G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:00:34.582 128M / 17G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:34.582 128M / 17G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60286 Gb 0:00:34.582 128M / 17G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:00:44.410 17G / 17G INFO General (kmer_splitters.hpp : 380) Processed 54024 kmers 0:00:44.410 17G / 17G INFO General (kmer_splitters.hpp : 385) Used 54024 kmers. 0:00:46.534 128M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:52.767 128M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 54161 kmers in total. 0:00:52.767 128M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:54.953 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:54.997 128M / 17G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:55.089 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 33984 bytes occupied (5.0197 bits per kmer). 0:00:55.089 128M / 17G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:55.106 128M / 17G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:55.110 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:55.117 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:55.122 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1106 sequences extracted 0:00:55.126 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:55.133 128M / 17G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:00:55.135 128M / 17G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:55.135 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:55.135 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:55.273 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 43072 bytes occupied (6.3782 bits per kmer). 0:00:55.273 128M / 17G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:55.319 128M / 17G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:55.325 128M / 17G INFO General (construction.cpp : 464) Processed 2212 edges 0:00:55.339 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:55.339 128M / 17G INFO General (graph_pack.hpp : 101) Index refill 0:00:55.346 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:55.346 128M / 17G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:00:55.350 128M / 17G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:00:55.350 128M / 17G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60286 Gb 0:00:55.350 128M / 17G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:01:04.702 17G / 17G INFO General (edge_index_builders.hpp : 77) Processed 2212 edges 0:01:04.702 17G / 17G INFO General (edge_index_builders.hpp : 82) Used 2212 sequences. 0:01:06.773 128M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:01:13.060 128M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 54024 kmers in total. 0:01:13.060 128M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:01:15.345 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:01:15.368 128M / 17G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:01:15.437 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 33944 bytes occupied (5.02651 bits per kmer). 0:01:15.438 132M / 17G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:01:15.446 128M / 17G INFO General (edge_index.hpp : 92) Index refilled 0:01:15.477 128M / 17G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:01:15.478 128M / 17G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:01:15.483 128M / 17G INFO General (gap_closer.cpp : 138) Used 68 paired reads 0:01:15.483 128M / 17G INFO General (gap_closer.cpp : 140) Merging paired indices 0:01:15.483 128M / 17G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:01:15.484 128M / 17G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 0 gaps after checking 18 candidates 0:01:15.487 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:01:15.488 128M / 17G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:01:15.489 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:01:15.491 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:01:15.491 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial tip clipper 0:01:15.495 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial tip clipper triggered 186 times 0:01:15.495 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial ec remover 0:01:15.496 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial ec remover triggered 13 times 0:01:15.496 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Disconnecting edges with low flanking coverage 0:01:15.498 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Disconnecting edges with low flanking coverage triggered 24 times 0:01:15.498 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Initial isolated edge remover 0:01:15.499 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Initial isolated edge remover triggered 150 times 0:01:15.500 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Preliminary Simplification 0:01:15.500 128M / 17G INFO General (simplification.cpp : 357) Graph simplification started 0:01:15.500 128M / 17G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:01:15.501 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:01:15.501 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:15.503 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 136 times 0:01:15.503 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:15.507 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 17 times 0:01:15.507 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:15.508 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:01:15.508 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:01:15.509 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:15.509 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3 times 0:01:15.509 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:15.510 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:15.510 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 16 times 0:01:15.511 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 6 times 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2 times 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 5 times 0:01:15.511 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:01:15.511 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:15.513 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:01:15.514 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:15.514 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:01:15.515 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:15.515 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:01:15.516 128M / 17G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:01:15.516 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:15.516 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:15.516 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:15.517 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:15.517 128M / 17G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:15.517 128M / 17G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:01:15.517 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:01:15.517 128M / 17G INFO General (graph_pack.hpp : 101) Index refill 0:01:15.521 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:01:15.521 128M / 17G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:01:15.524 128M / 17G INFO General (file_limit.hpp : 32) Open file limit set to 1088 0:01:15.524 128M / 17G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.60286 Gb 0:01:15.524 128M / 17G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:01:24.925 17G / 17G INFO General (edge_index_builders.hpp : 82) Used 236 sequences. 0:01:26.794 128M / 17G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:01:31.845 128M / 17G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 25396 kmers in total. 0:01:31.845 128M / 17G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:01:34.331 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:01:34.357 128M / 17G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:01:34.424 128M / 17G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 20816 bytes occupied (6.55725 bits per kmer). 0:01:34.448 128M / 17G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:01:34.461 128M / 17G INFO General (edge_index.hpp : 92) Index refilled 0:01:34.491 128M / 17G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:01:34.491 128M / 17G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:01:34.494 128M / 17G INFO General (gap_closer.cpp : 138) Used 68 paired reads 0:01:34.494 128M / 17G INFO General (gap_closer.cpp : 140) Merging paired indices 0:01:34.494 128M / 17G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:01:34.495 128M / 17G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 0 gaps after checking 4 candidates 0:01:34.498 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Preliminary Paired Information Counting 0:01:34.500 128M / 17G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 2630 kmers to process 0:01:34.502 128M / 17G INFO General (graph_pack.hpp : 111) Normalizing done 0:01:34.502 128M / 17G INFO General (pair_info_count.cpp : 320) Min edge length for estimation: 900 0:01:34.502 128M / 17G INFO General (pair_info_count.cpp : 331) Estimating insert size for library #0 0:01:34.502 128M / 17G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 0:01:34.967 656M / 17G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:01:36.506 656M / 17G INFO General (sequence_mapper_notifier.h: 98) Total 68 reads processed 0:01:37.570 656M / 17G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 0:01:37.570 656M / 17G INFO General (pair_info_count.cpp : 213) 1 paired reads (1.47059% of all) aligned to long edges 0:01:37.574 128M / 17G INFO General (pair_info_count.cpp : 354) Insert size = 324, deviation = 0, left quantile = 324, right quantile = 324, read length = 151 0:01:37.673 320M / 17G INFO General (pair_info_count.cpp : 371) Filtering data for library #0 0:01:37.706 320M / 17G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:01:37.709 320M / 17G INFO General (sequence_mapper_notifier.h: 98) Total 68 reads processed 0:01:37.709 320M / 17G INFO General (pair_info_count.cpp : 383) Mapping library #0 0:01:37.710 320M / 17G INFO General (pair_info_count.cpp : 385) Mapping paired reads (takes a while) 0:01:37.710 320M / 17G INFO General (pair_info_count.cpp : 289) Left insert size quantile 324, right insert size quantile 324, filtering threshold 1, rounding threshold 0 0:01:37.749 332M / 17G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:01:37.754 332M / 17G INFO General (sequence_mapper_notifier.h: 98) Total 68 reads processed 0:01:37.760 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Preliminary Distance Estimation 0:01:37.760 128M / 17G INFO General (distance_estimation.cpp : 173) Processing library #0 0:01:37.760 128M / 17G INFO General (distance_estimation.cpp : 149) Weight Filter Done 0:01:37.760 128M / 17G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 0:01:37.763 128M / 17G INFO General (distance_estimation.cpp : 34) Filtering info 0:01:37.763 128M / 17G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 236 0:01:37.764 128M / 17G INFO General (pair_info_filters.hpp : 263) Done filtering 0:01:37.764 128M / 17G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 0:01:37.764 128M / 17G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 0:01:37.765 128M / 17G INFO General (distance_estimation.cpp : 160) Improving paired information 0:01:37.772 128M / 17G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 0; contradictional = 0 0:01:37.782 128M / 17G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 0; contradictional = 0 0:01:37.782 128M / 17G INFO General (distance_estimation.cpp : 103) Filling scaffolding index 0:01:37.782 128M / 17G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator 0:01:37.786 128M / 17G INFO General (distance_estimation.cpp : 34) Filtering info 0:01:37.786 128M / 17G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 236 0:01:37.786 128M / 17G INFO General (pair_info_filters.hpp : 263) Done filtering 0:01:37.786 128M / 17G INFO General (distance_estimation.cpp : 182) Clearing raw paired index 0:01:37.786 128M / 17G INFO StageManager (stage.cpp : 132) STAGE == Preliminary Repeat Resolving 0:01:37.786 128M / 17G INFO General (repeat_resolving.cpp : 56) Setting up preliminary path extend settings 0:01:37.786 128M / 17G INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving 0:01:37.786 128M / 17G INFO General (launcher.cpp : 477) ExSPAnder repeat resolving tool started 0:01:37.790 128M / 17G INFO General (launcher.cpp : 392) Creating main extenders, unique edge length = 2000 0:01:37.790 128M / 17G INFO General (extenders_logic.cpp : 472) Using 1 paired-end library 0:01:37.790 128M / 17G INFO General (extenders_logic.cpp : 473) Using 1 paired-end scaffolding library 0:01:37.790 128M / 17G INFO General (extenders_logic.cpp : 474) Using 0 single read libraries 0:01:37.790 128M / 17G INFO General (launcher.cpp : 420) Total number of extenders is 3 0:01:37.790 128M / 17G INFO General (path_extender.hpp : 885) Processed 0 paths from 117 (0%) === Stack Trace === [0x40ac28] [0x66e319] [0x67f6ab] [0x682125] [0x68d50a] [0x695098] [0x6955ae] [0x678ef7] [0x699527] [0x657ff2] [0x66c97e] [0x6563c9] [0x4c2e64] [0x55d191] [0x408c19] [0x40123c] [0x87b11b] [0x407c01] spades-core: /spades/assembler/src/common/modules/path_extend/paired_library.hpp:127: double path_extend::PairedInfoLibraryWithIndex::CountPairedInfo(path_extend::EdgeId, path_extend::EdgeId, int, bool) const [with Index = const omnigraph::de::PairedIndex&; path_extend::EdgeId = restricted::pure_pointer >]: Assertion `index_.size() != 0' failed. == Error == system call for: "['/usr/local/devel/ANNOTATION/jespinoz/anaconda/envs/mage_env/share/spades-3.13.0-0/bin/spades-core', '/home/jespinoz/metaspades_output/K55/configs/config.info', '/home/jespinoz/metaspades_output/K55/configs/mda_mode.info', '/home/jespinoz/metaspades_output/K55/configs/meta_mode.info']" finished abnormally, err code: -6 In case you have troubles running SPAdes, you can write to spades.support@cab.spbu.ru or report an issue on our GitHub repository github.com/ablab/spades Please provide us with params.txt and spades.log files from the output directory. ```

asl commented 5 years ago

Hello

Thank you for your interest in SPAdes.

It seems you're having only 68 reads. This does not seems to be a metagenome, nor part of it.

As a result we're seeing:

  0:01:37.570   656M / 17G   INFO    General                 (pair_info_count.cpp       : 209)   Edge pairs: 67108864 (rough upper limit)
  0:01:37.570   656M / 17G   INFO    General                 (pair_info_count.cpp       : 213)   1 paired reads (1.47059% of all) aligned to long edges
  0:01:37.574   128M / 17G   INFO    General                 (pair_info_count.cpp       : 354)     Insert size = 324, deviation = 0, left quantile = 324, right quantile = 324, read length = 151
  0:01:37.673   320M / 17G   INFO    General                 (pair_info_count.cpp       : 371)   Filtering data for library #0

Hence the error afterwards.

jolespin commented 5 years ago

Haha wow I didn't realize there were only 68 reads! I'm trying out a pipeline and ran it on the smallest sample I had. Thanks for responding so quickly.