asl
commented
3 years ago Well, since the problem happens only within Geneious, I would strong suggest you to contact their support, as the problem outside SPAdes' area of responsibility. We do not support, extend or otherwise connected with them.
Further information from the log:
[mem_sam_pe] paired reads have different names: "NB501042:283:H7LVFAFX2:1:11101:12953:1108_1:N:0:4", "NB501042:283:H7LVFAFX2:1:11101:12953:1108_2:N:0:4"
[mem_sam_pe] paired reads have different names: "NB501042:283:H7LVFAFX2:1:11101:2520:1139_1:N:0:4", "NB501042:283:H7LVFAFX2:1:11101:2520:1139_2:N:0:4"Hope this will help
RichStanton
Description of bug
I'm running spades within geneious, and it was crashing, whereas when I ran it manually in Ubuntu it completed. Further investigation showed that it's the '--careful' parameter that's causing problems, but only on files that I have run the deduplication process on in geneious. I.e. on my original data, spades completes with or without --careful. On deduplicated data, it only completes if I leave --careful out of the command line. The error I get is:
== Error == system call for: "['/usr/lib/spades/bin/spades-corrector-core', '/home/rich/3158-spades/mismatch_corrector/contigs/configs/corrector.info', '/home/rich/3158-spades/misc/assembled_contigs.fasta']" finished abnormally, err code: 255
======= SPAdes pipeline finished abnormally and WITH WARNINGS!
=== Error correction and assembling warnings:
=== ERRORs:
Any ideas?
spades.log
Command line: /usr/lib/spades/bin/spades.py --careful -1 /home/rich/3158-1.fastq -2 /home/rich/3158-2.fastq -o /home/rich/3158-spades
System information: SPAdes version: 3.13.1 Python version: 3.9.5 OS: Linux-5.11.0-31-generic-x86_64-with-glibc2.33
Output dir: /home/rich/3158-spades Mode: read error correction and assembling Debug mode is turned OFF
Dataset parameters: Multi-cell mode (you should set '--sc' flag if input data was obtained with MDA (single-cell) technology or --meta flag if processing metagenomic dataset) Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/home/rich/3158-1.fastq'] right reads: ['/home/rich/3158-2.fastq'] 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 ON MismatchCorrector will be used Coverage cutoff is turned OFF Other parameters: Dir for temp files: /home/rich/3158-spades/tmp Threads: 16 Memory limit (in Gb): 31
======= SPAdes pipeline started. Log can be found here: /home/rich/3158-spades/spades.log
===== Read error correction started.
== Running read error correction tool: /usr/lib/spades/bin/spades-hammer /home/rich/3158-spades/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 /home/rich/3158-spades/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): 4 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 31 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.000 4M / 4M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:00.000 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:00.000 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58301 Gb 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 1048576 0:00:00.000 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /home/rich/3158-1.fastq 0:00:00.802 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 111552 reads 0:00:00.802 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 97) Processing /home/rich/3158-2.fastq 0:00:01.560 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 107) Processed 223104 reads 0:00:01.560 3G / 3G INFO K-mer Splitting (kmer_data.cpp : 112) Total 223104 reads processed 0:00:01.572 16M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:01.660 16M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 7193224 kmers in total. 0:00:01.660 16M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:01.693 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:01.887 16M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:01.963 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 3343920 bytes occupied (3.71897 bits per kmer). 0:00:01.964 16M / 3G INFO K-mer Counting (kmer_data.cpp : 356) Arranging kmers in hash map order 0:00:02.127 128M / 3G INFO General (main.cpp : 148) Clustering Hamming graph. 0:00:10.265 128M / 3G INFO General (main.cpp : 155) Extracting clusters 0:00:11.259 128M / 3G INFO General (main.cpp : 167) Clustering done. Total clusters: 3513359 0:00:11.262 72M / 3G INFO K-mer Counting (kmer_data.cpp : 376) Collecting K-mer information, this takes a while. 0:00:11.304 240M / 3G INFO K-mer Counting (kmer_data.cpp : 382) Processing /home/rich/3158-1.fastq 0:00:14.247 240M / 3G INFO K-mer Counting (kmer_data.cpp : 382) Processing /home/rich/3158-2.fastq 0:00:17.387 240M / 3G INFO K-mer Counting (kmer_data.cpp : 389) Collection done, postprocessing. 0:00:17.406 240M / 3G INFO K-mer Counting (kmer_data.cpp : 402) There are 7193224 kmers in total. Among them 5051758 (70.2294%) are singletons. 0:00:17.406 240M / 3G INFO General (main.cpp : 173) Subclustering Hamming graph 0:00:54.447 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 649) Subclustering done. Total 92 non-read kmers were generated. 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 650) Subclustering statistics: 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 651) Total singleton hamming clusters: 2847272. Among them 327760 (11.5114%) are good 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 652) Total singleton subclusters: 17600. Among them 17534 (99.625%) are good 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 653) Total non-singleton subcluster centers: 806543. Among them 596198 (73.9202%) are good 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 654) Average size of non-trivial subcluster: 5.38873 kmers 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 655) Average number of sub-clusters per non-singleton cluster: 1.23729 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 656) Total solid k-mers: 941492 0:00:54.448 240M / 3G INFO Hamming Subclustering (kmer_cluster.cpp : 657) Substitution probabilities: 4,4 0:00:54.451 240M / 3G INFO General (main.cpp : 178) Finished clustering. 0:00:54.451 240M / 3G INFO General (main.cpp : 197) Starting solid k-mers expansion in 4 threads. 0:00:56.407 240M / 3G INFO General (main.cpp : 218) Solid k-mers iteration 0 produced 200321 new k-mers. 0:00:58.322 240M / 3G INFO General (main.cpp : 218) Solid k-mers iteration 1 produced 19661 new k-mers. 0:01:00.254 240M / 3G INFO General (main.cpp : 218) Solid k-mers iteration 2 produced 1626 new k-mers. 0:01:02.126 240M / 3G INFO General (main.cpp : 218) Solid k-mers iteration 3 produced 8 new k-mers. 0:01:02.127 240M / 3G INFO General (main.cpp : 222) Solid k-mers finalized 0:01:02.127 240M / 3G INFO General (hammer_tools.cpp : 220) Starting read correction in 4 threads. 0:01:02.127 240M / 3G INFO General (hammer_tools.cpp : 233) Correcting pair of reads: /home/rich/3158-1.fastq and /home/rich/3158-2.fastq 0:01:02.310 404M / 3G INFO General (hammer_tools.cpp : 168) Prepared batch 0 of 111552 reads. 0:01:08.587 416M / 3G INFO General (hammer_tools.cpp : 175) Processed batch 0 0:01:08.730 416M / 3G INFO General (hammer_tools.cpp : 185) Written batch 0 0:01:08.774 240M / 3G INFO General (hammer_tools.cpp : 274) Correction done. Changed 224286 bases in 79553 reads. 0:01:08.774 240M / 3G INFO General (hammer_tools.cpp : 275) Failed to correct 456 bases out of 29865244. 0:01:08.783 16M / 3G INFO General (main.cpp : 255) Saving corrected dataset description to /home/rich/3158-spades/corrected/corrected.yaml 0:01:08.783 16M / 3G INFO General (main.cpp : 262) All done. Exiting.
== Compressing corrected reads (with gzip)
== Dataset description file was created: /home/rich/3158-spades/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/rich/3158-spades/K21/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/rich/3158-spades/K21/configs/careful_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 31 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 84) 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 (/home/rich/3158-spades/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): 4 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 : 77) Converting reads to binary format for library #0 (takes a while) 0:00:00.000 4M / 4M INFO General (read_converter.hpp : 78) Converting paired reads 0:00:00.114 76M / 84M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:00:00.197 88M / 88M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:00:00.358 112M / 112M INFO General (binary_converter.hpp : 93) 65536 reads processed 0:00:00.828 140M / 140M INFO General (binary_converter.hpp : 117) 111090 reads written 0:00:00.855 4M / 140M INFO General (read_converter.hpp : 87) Converting single reads 0:00:00.921 132M / 164M INFO General (binary_converter.hpp : 117) 458 reads written 0:00:00.925 4M / 164M INFO General (read_converter.hpp : 95) Converting merged reads 0:00:00.988 132M / 164M INFO General (binary_converter.hpp : 117) 0 reads written 0:00:00.992 4M / 164M INFO General (construction.cpp : 111) Max read length 151 0:00:00.992 4M / 164M INFO General (construction.cpp : 117) Average read length 133.834 0:00:00.992 4M / 164M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.992 4M / 164M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 16 files using 4 threads. This might take a while. 0:00:00.992 4M / 164M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.992 4M / 164M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58301 Gb 0:00:00.992 4M / 164M INFO General (kmer_splitters.hpp : 97) Using cell size of 4194304 0:00:01.833 2G / 2G INFO General (kmer_splitters.hpp : 289) Processed 445276 reads 0:00:01.833 2G / 2G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:01.844 16M / 2G INFO General (kmer_splitters.hpp : 308) Used 445276 reads 0:00:01.844 16M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:01.866 16M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 1920890 kmers in total. 0:00:01.866 16M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:01.875 16M / 2G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:01.875 16M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:01.875 16M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:01.875 16M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:01.875 16M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58203 Gb 0:00:01.875 16M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 1048576 0:00:02.046 3G / 3G INFO General (kmer_splitters.hpp : 380) Processed 1920890 kmers 0:00:02.046 3G / 3G INFO General (kmer_splitters.hpp : 385) Used 1920890 kmers. 0:00:02.053 16M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:02.077 16M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 1884409 kmers in total. 0:00:02.078 16M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:02.088 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:02.151 16M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:02.170 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 882224 bytes occupied (3.74536 bits per kmer). 0:00:02.171 16M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:02.275 16M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:02.276 16M / 3G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:00:02.276 16M / 3G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:00:02.276 16M / 3G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:00:02.478 16M / 3G INFO Early tip clipping (early_simplification.hpp : 184) 617848 22-mers were removed by early tip clipper 0:00:02.478 16M / 3G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:02.502 16M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:02.629 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 98907 sequences extracted 0:00:02.692 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:02.726 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 5 loops collected 0:00:02.760 36M / 3G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:02.760 36M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:02.760 36M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:02.828 40M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 892776 bytes occupied (3.71818 bits per kmer). 0:00:02.830 48M / 3G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:03.648 44M / 3G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:03.737 44M / 3G INFO General (construction.cpp : 464) Processed 197790 edges 0:00:03.743 36M / 3G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:03.744 36M / 3G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 37 0:00:03.744 36M / 3G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 59 0:00:03.744 36M / 3G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 61. Coverage mad: 11.8608 0:00:03.744 36M / 3G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:03.815 36M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:04.024 36M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:04.788 36M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:06.182 36M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:08.673 36M / 3G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 62.1014. Fitted coverage std. dev: 9.93408 0:00:08.675 36M / 3G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.661854 0:00:08.675 36M / 3G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 58 0:00:08.675 36M / 3G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 49 0:00:08.675 36M / 3G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 259666 0:00:08.675 36M / 3G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 62.1014 0:00:08.676 36M / 3G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 49 0:00:08.676 36M / 3G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:00:08.676 36M / 3G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:08.676 36M / 3G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:08.676 36M / 3G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 0:00:08.676 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:08.681 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:08.681 36M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:08.681 36M / 3G INFO General (simplification.cpp : 357) Graph simplification started 0:00:08.681 36M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:08.681 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:08.681 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:08.697 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1906 times 0:00:08.697 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:10.585 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 6702 times 0:00:10.585 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:10.848 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 22913 times 0:00:10.849 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:10.849 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:10.860 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 853 times 0:00:10.860 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.068 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1369 times 0:00:11.068 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.092 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2255 times 0:00:11.092 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:11.092 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.093 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 7 times 0:00:11.093 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.156 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 507 times 0:00:11.156 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.167 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 902 times 0:00:11.167 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:11.167 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.168 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3 times 0:00:11.168 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.195 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 258 times 0:00:11.195 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.200 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 419 times 0:00:11.200 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:11.200 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.201 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:11.201 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.215 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 144 times 0:00:11.215 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.219 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 314 times 0:00:11.219 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:00:11.219 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.220 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2 times 0:00:11.220 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.231 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 116 times 0:00:11.231 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.233 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 205 times 0:00:11.234 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:00:11.234 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.234 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:11.234 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.241 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 86 times 0:00:11.241 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.243 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 139 times 0:00:11.243 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:00:11.243 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.243 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:11.243 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.247 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 46 times 0:00:11.247 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.249 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 123 times 0:00:11.249 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:00:11.249 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.249 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:11.249 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.253 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 66 times 0:00:11.253 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.254 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 90 times 0:00:11.254 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:00:11.255 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.255 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:11.255 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.257 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 41 times 0:00:11.257 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.258 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 53 times 0:00:11.258 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:00:11.258 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.259 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3 times 0:00:11.259 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.262 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 32 times 0:00:11.262 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.268 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:11.268 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:00:11.268 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.268 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:11.268 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.269 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:11.269 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:11.269 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:11.269 36M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:11.269 36M / 3G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:11.269 36M / 3G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 0:00:11.269 36M / 3G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 0:00:11.269 36M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:11.269 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.269 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:11.269 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.271 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:11.271 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:11.272 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:11.272 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:11.274 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:11.274 36M / 3G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:11.275 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:00:11.285 32M / 3G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 790 times 0:00:11.285 32M / 3G INFO General (simplification.cpp : 470) Counting average coverage 0:00:11.286 32M / 3G INFO General (simplification.cpp : 476) Average coverage = 57.214 0:00:11.286 32M / 3G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:11.286 32M / 3G INFO General (contig_output.hpp : 22) Outputting contigs to /home/rich/3158-spades//K21/simplified_contigs.fasta 0:00:11.294 32M / 3G INFO General (launch.hpp : 151) SPAdes finished 0:00:11.305 16M / 3G INFO General (main.cpp : 109) Assembling time: 0 hours 0 minutes 11 seconds Max read length detected as 151 Default k-mer sizes were set to [21, 33, 55, 77] because estimated read length (151) is equal to or greater than 150
== Running assembler: K33
0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/rich/3158-spades/K33/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/rich/3158-spades/K33/configs/careful_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 31 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 84) 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 (/home/rich/3158-spades/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): 4 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.000 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.000 4M / 4M INFO General (construction.cpp : 117) Average read length 133.834 0:00:00.000 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.000 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 16 files using 4 threads. This might take a while. 0:00:00.000 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58301 Gb 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 2097152 0:00:00.825 2G / 2G INFO General (kmer_splitters.hpp : 289) Processed 445276 reads 0:00:00.825 2G / 2G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:00.876 16M / 2G INFO General (kmer_splitters.hpp : 308) Used 445276 reads 0:00:00.876 16M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:00.905 16M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2344421 kmers in total. 0:00:00.905 16M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:00.931 16M / 2G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:00.931 16M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:00.931 16M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:00.931 16M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.931 16M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58203 Gb 0:00:00.931 16M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:00:01.143 3G / 3G INFO General (kmer_splitters.hpp : 380) Processed 2344421 kmers 0:00:01.143 3G / 3G INFO General (kmer_splitters.hpp : 385) Used 2344421 kmers. 0:00:01.153 16M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:01.180 16M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2308998 kmers in total. 0:00:01.180 16M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:01.204 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:01.280 16M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:01.331 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1079072 bytes occupied (3.73867 bits per kmer). 0:00:01.333 16M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:01.469 16M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:01.469 16M / 3G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:00:01.469 16M / 3G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:00:01.469 16M / 3G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:00:01.725 20M / 3G INFO Early tip clipping (early_simplification.hpp : 184) 846084 34-mers were removed by early tip clipper 0:00:01.725 20M / 3G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:01.741 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:01.884 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 103883 sequences extracted 0:00:01.958 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:02.001 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 8 loops collected 0:00:02.045 44M / 3G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:02.045 44M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:02.045 44M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:02.110 48M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1089112 bytes occupied (3.71644 bits per kmer). 0:00:02.114 60M / 3G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:02.669 56M / 3G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:02.770 56M / 3G INFO General (construction.cpp : 464) Processed 207767 edges 0:00:02.778 40M / 3G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:02.778 40M / 3G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 33 0:00:02.778 40M / 3G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 54 0:00:02.778 40M / 3G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 55. Coverage mad: 10.3782 0:00:02.778 40M / 3G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:02.836 40M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:02.993 40M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:03.465 40M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:03.817 40M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:04.204 36M / 3G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 54.8777. Fitted coverage std. dev: 9.538 0:00:04.205 36M / 3G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.570673 0:00:04.205 36M / 3G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 55 0:00:04.205 36M / 3G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 43 0:00:04.205 36M / 3G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 256435 0:00:04.205 36M / 3G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 54.8777 0:00:04.205 36M / 3G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 43 0:00:04.205 36M / 3G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:00:04.205 36M / 3G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:04.205 36M / 3G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:04.205 36M / 3G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 0:00:04.205 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:04.217 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:04.217 36M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:04.217 36M / 3G INFO General (simplification.cpp : 357) Graph simplification started 0:00:04.217 36M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:04.217 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:04.217 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:04.240 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2657 times 0:00:04.240 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.304 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3796 times 0:00:05.305 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.653 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 25878 times 0:00:05.653 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:05.653 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.663 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 835 times 0:00:05.664 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.913 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1199 times 0:00:05.913 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.944 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2524 times 0:00:05.944 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:05.944 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.946 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 25 times 0:00:05.946 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.035 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 587 times 0:00:06.035 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.045 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 895 times 0:00:06.045 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:06.045 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.046 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 8 times 0:00:06.046 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.078 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 278 times 0:00:06.078 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.084 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 440 times 0:00:06.084 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:06.084 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.084 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 3 times 0:00:06.084 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.099 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 159 times 0:00:06.099 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.103 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 235 times 0:00:06.103 40M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:00:06.103 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.103 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2 times 0:00:06.103 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.111 40M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 86 times 0:00:06.111 40M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.113 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 164 times 0:00:06.113 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:00:06.113 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.114 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.114 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.117 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 58 times 0:00:06.117 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.119 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 98 times 0:00:06.119 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:00:06.119 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.119 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:06.119 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.120 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 32 times 0:00:06.120 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.122 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 86 times 0:00:06.122 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:00:06.122 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.122 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:06.122 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.124 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 33 times 0:00:06.124 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.125 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 58 times 0:00:06.125 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:00:06.125 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.126 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.126 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.126 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 21 times 0:00:06.126 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.127 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 62 times 0:00:06.127 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:00:06.127 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.128 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2 times 0:00:06.128 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.132 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 33 times 0:00:06.132 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.136 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:06.136 36M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:00:06.136 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.139 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.139 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.139 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.139 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.139 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:06.139 36M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:06.139 36M / 3G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:06.139 36M / 3G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 0:00:06.139 36M / 3G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 0:00:06.139 36M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:06.139 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.139 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.140 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.141 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.141 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.141 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.141 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.142 36M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.142 36M / 3G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:06.143 36M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:00:06.165 20M / 3G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 1465 times 0:00:06.165 20M / 3G INFO General (simplification.cpp : 470) Counting average coverage 0:00:06.165 20M / 3G INFO General (simplification.cpp : 476) Average coverage = 47.6494 0:00:06.165 20M / 3G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:06.165 20M / 3G INFO General (contig_output.hpp : 22) Outputting contigs to /home/rich/3158-spades//K33/simplified_contigs.fasta 0:00:06.171 20M / 3G INFO General (launch.hpp : 151) SPAdes finished 0:00:06.178 16M / 3G INFO General (main.cpp : 109) Assembling time: 0 hours 0 minutes 6 seconds
== Running assembler: K55
0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/rich/3158-spades/K55/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/rich/3158-spades/K55/configs/careful_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 31 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 84) 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 (/home/rich/3158-spades/dataset.info) with K=55 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 4 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 General (launch.hpp : 77) Will need read mapping, kmer mapper will be attached 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.000 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.000 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.000 4M / 4M INFO General (construction.cpp : 117) Average read length 133.834 0:00:00.000 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.000 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 16 files using 4 threads. This might take a while. 0:00:00.000 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58301 Gb 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 2097152 0:00:00.657 2G / 2G INFO General (kmer_splitters.hpp : 289) Processed 445276 reads 0:00:00.657 2G / 2G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:00.705 16M / 2G INFO General (kmer_splitters.hpp : 308) Used 445276 reads 0:00:00.706 16M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:00.746 16M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2951069 kmers in total. 0:00:00.746 16M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:00.775 16M / 2G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:00.775 16M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:00.775 16M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:00.775 16M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.775 16M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58203 Gb 0:00:00.775 16M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:00:01.054 3G / 3G INFO General (kmer_splitters.hpp : 380) Processed 2951069 kmers 0:00:01.054 3G / 3G INFO General (kmer_splitters.hpp : 385) Used 2951069 kmers. 0:00:01.063 16M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:01.098 16M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2934905 kmers in total. 0:00:01.098 16M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:01.124 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:01.209 16M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:01.266 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1369320 bytes occupied (3.73251 bits per kmer). 0:00:01.267 20M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:01.442 20M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:01.443 20M / 3G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:01.451 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:01.686 28M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 162058 sequences extracted 0:00:01.816 28M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:01.870 28M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:00:01.934 68M / 3G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:01.934 68M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:01.934 68M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:02.011 72M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1370464 bytes occupied (3.71517 bits per kmer). 0:00:02.018 84M / 3G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:02.519 84M / 3G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:02.731 84M / 3G INFO General (construction.cpp : 464) Processed 324103 edges 0:00:02.740 64M / 3G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:02.741 64M / 3G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 25 0:00:02.741 64M / 3G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 40 0:00:02.741 64M / 3G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 42. Coverage mad: 8.8956 0:00:02.741 64M / 3G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:02.763 64M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:02.825 64M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:02.930 64M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:02.993 64M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:03.015 64M / 3G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 42.3492. Fitted coverage std. dev: 8.22834 0:00:03.016 64M / 3G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.502617 0:00:03.016 64M / 3G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 42 0:00:03.016 64M / 3G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 33 0:00:03.016 64M / 3G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 237660 0:00:03.016 64M / 3G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 42.3492 0:00:03.016 64M / 3G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 33 0:00:03.016 64M / 3G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:00:03.016 64M / 3G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:03.016 64M / 3G INFO General (graph_pack.hpp : 101) Index refill 0:00:03.016 64M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:03.016 64M / 3G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:03.016 64M / 3G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:03.016 64M / 3G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.57812 Gb 0:00:03.016 64M / 3G INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:00:03.147 3G / 3G INFO General (edge_index_builders.hpp : 77) Processed 324103 edges 0:00:03.147 3G / 3G INFO General (edge_index_builders.hpp : 82) Used 324103 sequences. 0:00:03.153 56M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:03.192 56M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2951069 kmers in total. 0:00:03.192 56M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:03.220 56M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:03.310 64M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:03.372 64M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1376824 bytes occupied (3.73241 bits per kmer). 0:00:03.394 132M / 3G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:00:03.585 132M / 3G INFO General (edge_index.hpp : 92) Index refilled 0:00:03.585 132M / 3G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:00:03.685 140M / 3G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:00:03.950 148M / 3G INFO General (gap_closer.cpp : 138) Used 111090 paired reads 0:00:03.950 148M / 3G INFO General (gap_closer.cpp : 140) Merging paired indices 0:00:03.976 140M / 3G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:00:04.158 140M / 3G INFO GapCloser (gap_closer.cpp : 378) Closing short gaps complete: filled 14 gaps after checking 1722 candidates 0:00:04.166 136M / 3G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:04.170 64M / 3G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:04.171 64M / 3G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 0:00:04.171 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:04.181 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:04.182 64M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:04.182 64M / 3G INFO General (simplification.cpp : 357) Graph simplification started 0:00:04.182 64M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:04.182 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:04.182 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:04.550 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 51011 times 0:00:04.550 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.261 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1563 times 0:00:05.262 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.534 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 15385 times 0:00:05.534 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:05.534 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.555 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1409 times 0:00:05.556 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.854 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 756 times 0:00:05.854 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.880 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1730 times 0:00:05.880 72M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:05.880 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.882 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 64 times 0:00:05.882 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.947 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 280 times 0:00:05.948 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.956 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 512 times 0:00:05.956 72M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:05.956 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.957 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 20 times 0:00:05.957 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.979 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 106 times 0:00:05.980 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.983 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 235 times 0:00:05.983 72M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:05.984 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.984 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 9 times 0:00:05.984 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.991 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 38 times 0:00:05.992 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.994 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 125 times 0:00:05.994 72M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:00:05.994 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.994 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2 times 0:00:05.994 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.997 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 14 times 0:00:05.997 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.998 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 87 times 0:00:05.998 72M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:00:05.998 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.998 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:05.998 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.000 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 7 times 0:00:06.000 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.002 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 66 times 0:00:06.002 72M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:00:06.002 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.002 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 4 times 0:00:06.002 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.003 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 5 times 0:00:06.004 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.004 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 55 times 0:00:06.004 72M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:00:06.004 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.005 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.005 72M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.005 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3 times 0:00:06.005 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.006 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 41 times 0:00:06.006 68M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:00:06.006 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.006 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.006 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.006 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.006 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.007 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 30 times 0:00:06.007 68M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:00:06.007 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.008 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:06.008 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.010 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 4 times 0:00:06.010 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.011 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1 times 0:00:06.011 68M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:00:06.011 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.011 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.011 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.011 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.011 68M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:06.011 68M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:06.012 68M / 3G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:06.012 68M / 3G INFO General (graph_pack.hpp : 101) Index refill 0:00:06.012 68M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:06.012 68M / 3G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:06.012 68M / 3G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:06.012 68M / 3G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.5778 Gb 0:00:06.012 68M / 3G INFO General (kmer_splitters.hpp : 97) Using cell size of 524288 0:00:06.047 3G / 3G INFO General (edge_index_builders.hpp : 77) Processed 10599 edges 0:00:06.047 3G / 3G INFO General (edge_index_builders.hpp : 82) Used 10599 sequences. 0:00:06.052 68M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:06.072 68M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 802951 kmers in total. 0:00:06.072 68M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:06.081 68M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:06.118 68M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:06.135 68M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 380680 bytes occupied (3.79281 bits per kmer). 0:00:06.146 88M / 3G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:00:06.184 88M / 3G INFO General (edge_index.hpp : 92) Index refilled 0:00:06.184 88M / 3G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:00:06.190 92M / 3G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:00:06.886 92M / 3G INFO General (gap_closer.cpp : 138) Used 111090 paired reads 0:00:06.886 92M / 3G INFO General (gap_closer.cpp : 140) Merging paired indices 0:00:06.889 88M / 3G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:00:06.895 88M / 3G INFO GapCloser (gap_closer.cpp : 378) Closing short gaps complete: filled 2 gaps after checking 114 candidates 0:00:06.897 88M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:06.897 88M / 3G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:06.897 88M / 3G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 0:00:06.897 88M / 3G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 0:00:06.897 88M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:06.897 88M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.898 88M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.899 88M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.899 88M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.899 88M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.900 88M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.900 88M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.901 88M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.901 88M / 3G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:06.903 88M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:00:07.066 72M / 3G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 4757 times 0:00:07.066 72M / 3G INFO General (simplification.cpp : 470) Counting average coverage 0:00:07.067 72M / 3G INFO General (simplification.cpp : 476) Average coverage = 32.1816 0:00:07.067 72M / 3G WARN General (simplification.cpp : 479) The determined erroneous connection coverage threshold may be determined improperly 0:00:07.067 72M / 3G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:07.067 72M / 3G INFO General (contig_output.hpp : 22) Outputting contigs to /home/rich/3158-spades//K55/simplified_contigs.fasta 0:00:07.071 72M / 3G INFO General (launch.hpp : 151) SPAdes finished 0:00:07.127 20M / 3G INFO General (main.cpp : 109) Assembling time: 0 hours 0 minutes 7 seconds
== Running assembler: K77
0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/rich/3158-spades/K77/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/rich/3158-spades/K77/configs/careful_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 31 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 84) 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 (/home/rich/3158-spades/dataset.info) with K=77 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 4 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 General (launch.hpp : 77) Will need read mapping, kmer mapper will be attached 0:00:00.000 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.000 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.000 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.000 4M / 4M INFO General (construction.cpp : 117) Average read length 133.834 0:00:00.000 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.000 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 16 files using 4 threads. This might take a while. 0:00:00.000 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58301 Gb 0:00:00.000 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 1398101 0:00:00.571 2G / 2G INFO General (kmer_splitters.hpp : 289) Processed 445276 reads 0:00:00.571 2G / 2G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:00.622 16M / 2G INFO General (kmer_splitters.hpp : 308) Used 445276 reads 0:00:00.622 16M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:00.672 16M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2987242 kmers in total. 0:00:00.672 16M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:00.714 16M / 2G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:00.714 16M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:00.714 16M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:00.714 16M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.714 16M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.58203 Gb 0:00:00.714 16M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 349525 0:00:01.040 3G / 3G INFO General (kmer_splitters.hpp : 380) Processed 2987242 kmers 0:00:01.040 3G / 3G INFO General (kmer_splitters.hpp : 385) Used 2987242 kmers. 0:00:01.052 16M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:01.096 16M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2997236 kmers in total. 0:00:01.096 16M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:01.138 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:01.232 16M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:01.326 16M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1398176 bytes occupied (3.73191 bits per kmer). 0:00:01.327 20M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:01.523 20M / 3G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:01.523 20M / 3G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:01.543 20M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:01.841 24M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 118466 sequences extracted 0:00:02.001 24M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:02.062 24M / 3G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:00:02.121 56M / 3G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:02.121 56M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:02.121 56M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:02.205 56M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1387224 bytes occupied (3.71506 bits per kmer). 0:00:02.209 68M / 3G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:02.624 68M / 3G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:02.848 68M / 3G INFO General (construction.cpp : 464) Processed 236926 edges 0:00:02.859 52M / 3G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:02.859 52M / 3G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 18 0:00:02.859 52M / 3G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 29 0:00:02.859 52M / 3G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 30. Coverage mad: 7.413 0:00:02.859 52M / 3G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:02.867 52M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:02.895 52M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:02.980 52M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:03.147 52M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:03.463 52M / 3G INFO General (kmer_coverage_model.cpp : 295) ... iteration 32 0:00:03.757 52M / 3G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 28.9885. Fitted coverage std. dev: 8.42302 0:00:03.758 52M / 3G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.234347 0:00:03.758 52M / 3G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 29 0:00:03.758 52M / 3G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 23 0:00:03.758 52M / 3G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 228427 0:00:03.758 52M / 3G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 28.9885 0:00:03.758 52M / 3G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 23 0:00:03.758 52M / 3G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:00:03.758 52M / 3G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:03.758 52M / 3G INFO General (graph_pack.hpp : 101) Index refill 0:00:03.758 52M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:03.758 52M / 3G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:03.758 52M / 3G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:03.758 52M / 3G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.5791 Gb 0:00:03.758 52M / 3G INFO General (kmer_splitters.hpp : 97) Using cell size of 349525 0:00:03.909 3G / 3G INFO General (edge_index_builders.hpp : 77) Processed 236926 edges 0:00:03.909 3G / 3G INFO General (edge_index_builders.hpp : 82) Used 236926 sequences. 0:00:03.916 52M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:03.961 52M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2987242 kmers in total. 0:00:03.961 52M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:04.002 52M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:04.093 52M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:04.184 52M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 1393560 bytes occupied (3.73203 bits per kmer). 0:00:04.205 124M / 3G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:00:04.393 124M / 3G INFO General (edge_index.hpp : 92) Index refilled 0:00:04.393 124M / 3G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:00:04.493 136M / 3G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:00:04.682 144M / 3G INFO General (gap_closer.cpp : 138) Used 111090 paired reads 0:00:04.682 144M / 3G INFO General (gap_closer.cpp : 140) Merging paired indices 0:00:04.720 128M / 3G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:00:04.874 128M / 3G INFO GapCloser (gap_closer.cpp : 378) Closing short gaps complete: filled 50 gaps after checking 3761 candidates 0:00:04.892 128M / 3G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:04.894 56M / 3G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:04.894 56M / 3G INFO General (simplification.cpp : 62) Most init cleaning disabled on main iteration 0:00:04.894 56M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:04.904 56M / 3G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:04.904 56M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:04.904 56M / 3G INFO General (simplification.cpp : 357) Graph simplification started 0:00:04.904 56M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:04.904 56M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:04.904 56M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.211 56M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 44218 times 0:00:05.211 56M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.336 56M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 465 times 0:00:05.336 56M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.386 56M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3161 times 0:00:05.386 56M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:05.386 56M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.392 56M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 706 times 0:00:05.392 56M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.480 60M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 307 times 0:00:05.480 60M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.492 60M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 882 times 0:00:05.492 60M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:05.492 60M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.493 60M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 77 times 0:00:05.493 60M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.523 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 95 times 0:00:05.523 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.526 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 268 times 0:00:05.526 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:05.526 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.527 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 9 times 0:00:05.527 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.534 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 34 times 0:00:05.534 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.537 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 150 times 0:00:05.537 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:05.537 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.537 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 6 times 0:00:05.537 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.540 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 15 times 0:00:05.540 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.541 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 74 times 0:00:05.541 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:00:05.541 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.541 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:05.541 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.542 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2 times 0:00:05.542 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.543 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 67 times 0:00:05.543 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:00:05.543 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.543 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:05.543 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.543 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2 times 0:00:05.543 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 32 times 0:00:05.544 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 28 times 0:00:05.544 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 12 times 0:00:05.544 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 10 times 0:00:05.544 64M / 3G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:00:05.544 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:05.547 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:05.547 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:05.549 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:05.549 64M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:05.550 64M / 3G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:05.550 64M / 3G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:05.550 64M / 3G INFO General (graph_pack.hpp : 101) Index refill 0:00:05.550 64M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:05.550 64M / 3G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 4 threads. This might take a while. 0:00:05.550 64M / 3G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:05.550 64M / 3G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.57812 Gb 0:00:05.550 64M / 3G INFO General (kmer_splitters.hpp : 97) Using cell size of 349525 0:00:05.612 3G / 3G INFO General (edge_index_builders.hpp : 77) Processed 31458 edges 0:00:05.612 3G / 3G INFO General (edge_index_builders.hpp : 82) Used 31458 sequences. 0:00:05.618 64M / 3G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:05.646 64M / 3G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 1439374 kmers in total. 0:00:05.646 64M / 3G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:05.666 64M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:05.725 64M / 3G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:05.769 64M / 3G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 675904 bytes occupied (3.75666 bits per kmer). 0:00:05.786 100M / 3G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:00:05.862 100M / 3G INFO General (edge_index.hpp : 92) Index refilled 0:00:05.862 100M / 3G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:00:05.882 104M / 3G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:00:06.366 104M / 3G INFO General (gap_closer.cpp : 138) Used 111090 paired reads 0:00:06.366 104M / 3G INFO General (gap_closer.cpp : 140) Merging paired indices 0:00:06.379 100M / 3G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:00:06.395 100M / 3G INFO GapCloser (gap_closer.cpp : 378) Closing short gaps complete: filled 0 gaps after checking 88 candidates 0:00:06.399 100M / 3G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:06.399 100M / 3G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:06.399 100M / 3G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 0:00:06.399 100M / 3G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 0:00:06.399 100M / 3G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:00:06.399 100M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.403 100M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.404 100M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.405 100M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.405 100M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:06.407 100M / 3G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:06.407 100M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:06.409 100M / 3G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:06.409 100M / 3G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:06.415 100M / 3G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:00:06.857 84M / 3G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 15249 times 0:00:06.857 84M / 3G INFO General (simplification.cpp : 470) Counting average coverage 0:00:06.857 84M / 3G INFO General (simplification.cpp : 476) Average coverage = 20.9948 0:00:06.857 84M / 3G WARN General (simplification.cpp : 479) The determined erroneous connection coverage threshold may be determined improperly 0:00:06.857 84M / 3G INFO StageManager (stage.cpp : 132) STAGE == Mismatch Correction 0:00:06.857 84M / 3G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 164188 kmers to process 0:00:06.960 80M / 3G INFO General (graph_pack.hpp : 111) Normalizing done 0:00:08.160 84M / 3G INFO General (mismatch_shall_not_pass.hp: 189) Finished collecting potential mismatches positions 0:00:08.165 84M / 3G INFO General (mismatch_shall_not_pass.hp: 290) All edges processed 0:00:08.166 84M / 3G INFO General (mismatch_correction.cpp : 27) Corrected 0 nucleotides 0:00:08.166 84M / 3G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:08.166 84M / 3G INFO General (contig_output_stage.cpp : 45) Writing GFA to /home/rich/3158-spades//K77/assembly_graph_with_scaffolds.gfa 0:00:08.169 84M / 3G INFO General (contig_output.hpp : 22) Outputting contigs to /home/rich/3158-spades//K77/before_rr.fasta 0:00:08.173 84M / 3G INFO General (contig_output_stage.cpp : 56) Outputting FastG graph to /home/rich/3158-spades//K77/assembly_graph.fastg 0:00:08.181 84M / 3G INFO General (contig_output.hpp : 22) Outputting contigs to /home/rich/3158-spades//K77/final_contigs.fasta 0:00:08.185 84M / 3G INFO StageManager (stage.cpp : 132) STAGE == Paired Information Counting 0:00:08.186 84M / 3G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 164188 kmers to process 0:00:08.186 84M / 3G INFO General (graph_pack.hpp : 111) Normalizing done 0:00:08.186 84M / 3G INFO General (pair_info_count.cpp : 323) Min edge length for estimation: 16300 0:00:08.186 84M / 3G INFO General (pair_info_count.cpp : 334) Estimating insert size for library #0 0:00:08.186 84M / 3G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 0:00:08.209 164M / 3G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:00:08.764 164M / 3G INFO General (sequence_mapper_notifier.h: 98) Total 111090 reads processed 0:00:08.799 164M / 3G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 0:00:08.799 164M / 3G INFO General (pair_info_count.cpp : 211) 56215 paired reads (50.6031% of all) aligned to long edges 0:00:08.802 84M / 3G INFO General (pair_info_count.cpp : 353) Insert size = 229.848, deviation = 119.593, left quantile = 103, right quantile = 402, read length = 151 0:00:08.854 276M / 3G INFO General (pair_info_count.cpp : 374) Filtering data for library #0 0:00:08.854 276M / 3G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:00:09.346 276M / 3G INFO General (sequence_mapper_notifier.h: 98) Total 111090 reads processed 0:00:09.347 276M / 3G INFO General (pair_info_count.cpp : 386) Mapping library #0 0:00:09.347 276M / 3G INFO General (pair_info_count.cpp : 388) Mapping paired reads (takes a while) 0:00:09.347 276M / 3G INFO General (pair_info_count.cpp : 286) Left insert size quantile 103, right insert size quantile 402, filtering threshold 2, rounding threshold 0 0:00:09.351 288M / 3G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:00:09.863 288M / 3G INFO General (sequence_mapper_notifier.h: 98) Total 111090 reads processed 0:00:09.871 84M / 3G INFO StageManager (stage.cpp : 132) STAGE == Distance Estimation 0:00:09.872 84M / 3G INFO General (distance_estimation.cpp : 173) Processing library #0 0:00:09.872 84M / 3G INFO General (distance_estimation.cpp : 149) Weight Filter Done 0:00:09.872 84M / 3G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 0:00:09.873 84M / 3G INFO General (distance_estimation.cpp : 34) Filtering info 0:00:09.873 84M / 3G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2808 0:00:09.874 84M / 3G INFO General (pair_info_filters.hpp : 263) Done filtering 0:00:09.874 84M / 3G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 0:00:09.874 84M / 3G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 0:00:09.874 84M / 3G INFO General (distance_estimation.cpp : 160) Improving paired information 0:00:09.900 84M / 3G INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 17; contradictional = 16 0:00:09.927 84M / 3G INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 0; contradictional = 0 0:00:09.927 84M / 3G INFO General (distance_estimation.cpp : 103) Filling scaffolding index 0:00:09.928 84M / 3G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator 0:00:09.930 84M / 3G INFO General (distance_estimation.cpp : 34) Filtering info 0:00:09.930 84M / 3G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 1057 0:00:09.930 84M / 3G INFO General (pair_info_filters.hpp : 263) Done filtering 0:00:09.931 84M / 3G INFO General (distance_estimation.cpp : 182) Clearing raw paired index 0:00:09.931 84M / 3G INFO StageManager (stage.cpp : 132) STAGE == Repeat Resolving 0:00:09.931 84M / 3G INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving 0:00:09.931 84M / 3G INFO General (launcher.cpp : 481) ExSPAnder repeat resolving tool started 0:00:09.932 84M / 3G INFO General (launcher.cpp : 392) Creating main extenders, unique edge length = 2000 0:00:09.932 84M / 3G INFO General (extenders_logic.cpp : 278) Estimated coverage of library #0 is 20.9948 0:00:09.932 84M / 3G INFO General (extenders_logic.cpp : 278) Estimated coverage of library #0 is 20.9948 0:00:09.932 84M / 3G INFO General (extenders_logic.cpp : 475) Using 1 paired-end library 0:00:09.932 84M / 3G INFO General (extenders_logic.cpp : 476) Using 1 paired-end scaffolding library 0:00:09.932 84M / 3G INFO General (extenders_logic.cpp : 477) Using 0 single read libraries 0:00:09.932 84M / 3G INFO General (launcher.cpp : 420) Total number of extenders is 3 0:00:09.932 84M / 3G INFO General (path_extender.hpp : 885) Processed 0 paths from 414 (0%) 0:00:09.936 84M / 3G INFO General (path_extender.hpp : 885) Processed 42 paths from 414 (10%) 0:00:09.940 84M / 3G INFO General (path_extender.hpp : 885) Processed 84 paths from 414 (20%) 0:00:09.941 84M / 3G INFO General (path_extender.hpp : 885) Processed 126 paths from 414 (30%) 0:00:09.941 84M / 3G INFO General (path_extender.hpp : 883) Processed 128 paths from 414 (30%) 0:00:09.942 84M / 3G INFO General (path_extender.hpp : 885) Processed 168 paths from 414 (40%) 0:00:09.944 84M / 3G INFO General (path_extender.hpp : 885) Processed 210 paths from 414 (50%) 0:00:09.945 84M / 3G INFO General (path_extender.hpp : 885) Processed 252 paths from 414 (60%) 0:00:09.945 84M / 3G INFO General (path_extender.hpp : 883) Processed 256 paths from 414 (61%) 0:00:09.946 84M / 3G INFO General (path_extender.hpp : 885) Processed 294 paths from 414 (71%) 0:00:09.948 88M / 3G INFO General (path_extender.hpp : 885) Processed 336 paths from 414 (81%) 0:00:09.950 88M / 3G INFO General (path_extender.hpp : 885) Processed 378 paths from 414 (91%) 0:00:09.954 88M / 3G INFO General (launcher.cpp : 234) Finalizing paths 0:00:09.954 88M / 3G INFO General (launcher.cpp : 236) Deduplicating paths 0:00:09.955 88M / 3G INFO General (launcher.cpp : 240) Paths deduplicated 0:00:09.955 88M / 3G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 0:00:09.955 88M / 3G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths 0:00:09.955 88M / 3G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 0:00:09.955 88M / 3G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 0:00:09.956 88M / 3G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps 0:00:09.956 88M / 3G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 0:00:09.956 88M / 3G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 0:00:09.956 88M / 3G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 0:00:09.957 88M / 3G INFO General (launcher.cpp : 257) Paths finalized 0:00:09.957 88M / 3G INFO General (launcher.cpp : 427) Closing gaps in paths 0:00:09.958 88M / 3G INFO General (launcher.cpp : 455) Gap closing completed 0:00:09.958 88M / 3G INFO General (launcher.cpp : 286) Traversing tandem repeats 0:00:09.960 88M / 3G INFO General (launcher.cpp : 296) Traversed 0 loops 0:00:09.960 88M / 3G INFO General (launcher.cpp : 234) Finalizing paths 0:00:09.960 88M / 3G INFO General (launcher.cpp : 236) Deduplicating paths 0:00:09.960 88M / 3G INFO General (launcher.cpp : 240) Paths deduplicated 0:00:09.960 88M / 3G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 0:00:09.960 88M / 3G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths 0:00:09.960 88M / 3G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 0:00:09.960 88M / 3G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 0:00:09.960 88M / 3G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps 0:00:09.960 88M / 3G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 0:00:09.960 88M / 3G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 0:00:09.961 88M / 3G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 0:00:09.961 88M / 3G INFO General (launcher.cpp : 257) Paths finalized 0:00:09.961 88M / 3G INFO General (launcher.cpp : 534) ExSPAnder repeat resolving tool finished 0:00:09.962 84M / 3G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:09.962 84M / 3G INFO General (contig_output_stage.cpp : 45) Writing GFA to /home/rich/3158-spades//K77/assembly_graph_with_scaffolds.gfa 0:00:09.965 84M / 3G INFO General (contig_output.hpp : 22) Outputting contigs to /home/rich/3158-spades//K77/before_rr.fasta 0:00:09.970 84M / 3G INFO General (contig_output_stage.cpp : 56) Outputting FastG graph to /home/rich/3158-spades//K77/assembly_graph.fastg 0:00:09.983 84M / 3G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /home/rich/3158-spades//K77/final_contigs.paths 0:00:09.988 84M / 3G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /home/rich/3158-spades//K77/scaffolds.paths 0:00:09.994 84M / 3G INFO General (launch.hpp : 151) SPAdes finished 0:00:10.029 20M / 3G INFO General (main.cpp : 109) Assembling time: 0 hours 0 minutes 10 seconds
===== Assembling finished. Used k-mer sizes: 21, 33, 55, 77
===== Mismatch correction started.
== Processing of contigs
== Running contig polishing tool: /usr/lib/spades/bin/spades-corrector-core /home/rich/3158-spades/mismatch_corrector/contigs/configs/corrector.info /home/rich/3158-spades/misc/assembled_contigs.fasta
== Dataset description file was created: /home/rich/3158-spades/mismatch_corrector/contigs/configs/corrector.info
/home/rich/3158-spades/mismatch_corrector/contigs/configs/log.properties 0:00:00.000 4M / 4M INFO General (main.cpp : 58) Starting MismatchCorrector, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 59) Maximum # of threads to use (adjusted due to OMP capabilities): 4 0:00:00.000 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 195) Splitting assembly... 0:00:00.000 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 196) Assembly file: /home/rich/3158-spades/misc/assembled_contigs.fasta 0:00:00.008 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 203) Processing paired sublib of number 0 0:00:00.008 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 206) /home/rich/3158-1.fastq /home/rich/3158-2.fastq 0:00:00.008 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 140) Running bwa index ...: /usr/bin/bwa index -a is /home/rich/3158-spades/misc/assembled_contigs.fasta [bwa_index] Pack FASTA... 0.00 sec [bwa_index] Construct BWT for the packed sequence... [bwa_index] 0.06 seconds elapse. [bwa_index] Update BWT... 0.00 sec [bwa_index] Pack forward-only FASTA... 0.00 sec [bwa_index] Construct SA from BWT and Occ... 0.02 sec [main] Version: 0.7.17-r1188 [main] CMD: /usr/bin/bwa index -a is /home/rich/3158-spades/misc/assembled_contigs.fasta [main] Real time: 0.089 sec; CPU: 0.084 sec 0:00:00.099 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 149) Running bwa mem ...:/usr/bin/bwa mem -v 1 -t 4 /home/rich/3158-spades/misc/assembled_contigs.fasta /home/rich/3158-1.fastq /home/rich/3158-2.fastq > /home/rich/3158-spades/tmp/corrector_a5itfk5n/lib0_jF2r9K/tmp.sam [M::mem_pestat] skip orientation FF as there are not enough pairs [M::mem_pestat] analyzing insert size distribution for orientation FR... [M::mem_pestat] (25, 50, 75) percentile: (119, 176, 269) [M::mem_pestat] low and high boundaries for computing mean and std.dev: (1, 569) [M::mem_pestat] mean and std.dev: (201.62, 109.94) [M::mem_pestat] low and high boundaries for proper pairs: (1, 719) [M::mem_pestat] analyzing insert size distribution for orientation RF... [M::mem_pestat] (25, 50, 75) percentile: (1170, 1901, 5475) [M::mem_pestat] low and high boundaries for computing mean and std.dev: (1, 14085) [M::mem_pestat] mean and std.dev: (2749.60, 2091.87) [M::mem_pestat] low and high boundaries for proper pairs: (1, 18390) [M::mem_pestat] skip orientation RR as there are not enough pairs [M::mem_pestat] skip orientation RF [mem_sam_pe] paired reads have different names: "NB501042:283:H7LVFAFX2:1:11101:12953:1108_1:N:0:4", "NB501042:283:H7LVFAFX2:1:11101:12953:1108_2:N:0:4" [mem_sam_pe] paired reads have different names: "NB501042:283:H7LVFAFX2:1:11101:2520:1139_1:N:0:4", "NB501042:283:H7LVFAFX2:1:11101:2520:1139_2:N:0:4" 0:00:04.185 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 152) bwa failed, skipping sublib 0:00:04.185 4M / 4M ERROR DatasetProcessor (dataset_processor.cpp : 215) Failed to align paired reads /home/rich/3158-1.fastq and /home/rich/3158-2.fastq
== Error == system call for: "['/usr/lib/spades/bin/spades-corrector-core', '/home/rich/3158-spades/mismatch_corrector/contigs/configs/corrector.info', '/home/rich/3158-spades/misc/assembled_contigs.fasta']" finished abnormally, err code: 255
======= SPAdes pipeline finished abnormally and WITH WARNINGS!
=== Error correction and assembling warnings:
=== ERRORs:
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.
params.txt
Command line: /usr/lib/spades/bin/spades.py --careful -1 /home/rich/3158-1.fastq -2 /home/rich/3158-2.fastq -o /home/rich/3158-spades
System information: SPAdes version: 3.13.1 Python version: 3.9.5 OS: Linux-5.11.0-31-generic-x86_64-with-glibc2.33
Output dir: /home/rich/3158-spades Mode: read error correction and assembling Debug mode is turned OFF
Dataset parameters: Multi-cell mode (you should set '--sc' flag if input data was obtained with MDA (single-cell) technology or --meta flag if processing metagenomic dataset) Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/home/rich/3158-1.fastq'] right reads: ['/home/rich/3158-2.fastq'] 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 ON MismatchCorrector will be used Coverage cutoff is turned OFF Other parameters: Dir for temp files: /home/rich/3158-spades/tmp Threads: 16 Memory limit (in Gb): 31
SPAdes version
3.13
Operating System
Ubuntu 20.04
Python Version
3.8
Method of SPAdes installation
Apt
No errors reported in spades.log