Command line: /home/administrator/Software/SPAdes-3.13.1-Linux/bin/rnaspades.py --only-assembler -k 29,49 -m 245 -t 32 -o /DATA/markop/Pcitri_rnaspades_alldata/output --ss-rf --pe1-fr --pe2-fr --pe3-fr --pe1-12 /DATA/markop/Pcitri_rnaspades_alldata/input/SUSPHIRE_unmerged.fastq --pe1-s /DATA/markop/Pcitri_rnaspades_alldata/input/SUSPHIRE_SE.fastq --pe2-12 /DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh50_unmerged.fastq --pe2-s /DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh50_SE.fastq --pe3-12 /DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh75_unmerged.fastq --pe3-s /DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh75_SE.fastq System information: SPAdes version: 3.13.1 Python version: 2.7.12 OS: Linux-4.13.0-41-generic-x86_64-with-LinuxMint-18.2-sonya Output dir: /DATA/markop/Pcitri_rnaspades_alldata/output Mode: ONLY assembling (without read error correction) Debug mode is turned OFF Dataset parameters: RNA-seq mode Reads: Library number: 1, library type: paired-end orientation: fr left reads: not specified right reads: not specified interlaced reads: ['/DATA/markop/Pcitri_rnaspades_alldata/input/SUSPHIRE_unmerged.fastq'] single reads: ['/DATA/markop/Pcitri_rnaspades_alldata/input/SUSPHIRE_SE.fastq'] merged reads: not specified Library number: 2, library type: paired-end orientation: fr left reads: not specified right reads: not specified interlaced reads: ['/DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh50_unmerged.fastq'] single reads: ['/DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh50_SE.fastq'] merged reads: not specified Library number: 3, library type: paired-end orientation: fr left reads: not specified right reads: not specified interlaced reads: ['/DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh75_unmerged.fastq'] single reads: ['/DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh75_SE.fastq'] merged reads: not specified Assembly parameters: k: [29, 49] Repeat resolution is enabled Mismatch careful mode is turned OFF MismatchCorrector will be SKIPPED Coverage cutoff is turned OFF Other parameters: Dir for temp files: /DATA/markop/Pcitri_rnaspades_alldata/output/tmp Threads: 32 Memory limit (in Gb): 245 ======= SPAdes pipeline started. Log can be found here: /DATA/markop/Pcitri_rnaspades_alldata/output/spades.log == Splitting /DATA/markop/Pcitri_rnaspades_alldata/input/SUSPHIRE_unmerged.fastq into left and right reads (in /DATA/markop/Pcitri_rnaspades_alldata/output/split_input directory) == Splitting /DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh50_unmerged.fastq into left and right reads (in /DATA/markop/Pcitri_rnaspades_alldata/output/split_input directory) == Splitting /DATA/markop/Pcitri_rnaspades_alldata/input/Edinburgh75_unmerged.fastq into left and right reads (in /DATA/markop/Pcitri_rnaspades_alldata/output/split_input directory) ===== Assembling started. == Running assembler: K29 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades_alldata/output/K29/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades_alldata/output/K29/configs/mda_mode.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades_alldata/output/K29/configs/rna_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 245 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from refs/heads/spades_3.13.1, git revision 9a9d54db2ff9abaac718155bf74c12ec9464e8ca 0:00:00.000 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.000 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/DATA/markop/Pcitri_rnaspades_alldata/output/dataset.info) with K=29 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.000 4M / 4M INFO General (launch.hpp : 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.001 4M / 4M INFO General (read_converter.hpp : 77) Converting reads to binary format for library #0 (takes a while) 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 78) Converting paired reads 0:00:00.169 80M / 80M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:00:00.261 96M / 96M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:00:00.455 124M / 124M INFO General (binary_converter.hpp : 93) 65536 reads processed 0:00:00.816 176M / 176M INFO General (binary_converter.hpp : 93) 131072 reads processed 0:00:01.598 288M / 288M INFO General (binary_converter.hpp : 93) 262144 reads processed 0:00:03.338 508M / 508M INFO General (binary_converter.hpp : 93) 524288 reads processed 0:00:09.739 852M / 852M INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:00:20.163 860M / 860M INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:00:42.468 868M / 868M INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:01:30.087 876M / 876M INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:03:01.327 896M / 896M INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:06:00.086 908M / 912M INFO General (binary_converter.hpp : 93) 33554432 reads processed 0:08:25.902 804M / 912M INFO General (binary_converter.hpp : 117) 47754126 reads written 0:08:26.588 8M / 912M INFO General (read_converter.hpp : 87) Converting single reads 0:08:26.770 140M / 912M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:08:26.829 152M / 912M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:08:26.949 172M / 912M INFO General (binary_converter.hpp : 93) 65536 reads processed 0:08:27.183 208M / 912M INFO General (binary_converter.hpp : 93) 131072 reads processed 0:08:27.657 288M / 912M INFO General (binary_converter.hpp : 93) 262144 reads processed 0:08:28.615 440M / 912M INFO General (binary_converter.hpp : 93) 524288 reads processed 0:08:31.384 752M / 912M INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:08:35.987 1G / 1G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:08:45.333 2G / 2G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:09:09.732 2G / 2G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:09:55.248 2G / 2G INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:11:32.696 2G / 2G INFO General (binary_converter.hpp : 93) 33554432 reads processed 0:14:49.176 2G / 2G INFO General (binary_converter.hpp : 93) 67108864 reads processed 0:21:31.285 2G / 2G INFO General (binary_converter.hpp : 93) 134217728 reads processed 0:35:43.317 2G / 2G INFO General (binary_converter.hpp : 93) 268435456 reads processed 0:37:29.736 1G / 2G INFO General (binary_converter.hpp : 117) 283878849 reads written 0:37:32.456 8M / 2G INFO General (read_converter.hpp : 95) Converting merged reads 0:37:32.565 136M / 2G INFO General (binary_converter.hpp : 117) 0 reads written 0:37:32.922 8M / 2G INFO General (read_converter.hpp : 77) Converting reads to binary format for library #1 (takes a while) 0:37:32.922 8M / 2G INFO General (read_converter.hpp : 78) Converting paired reads 0:37:33.058 76M / 2G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:37:33.109 84M / 2G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:37:33.210 100M / 2G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:37:33.432 132M / 2G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:37:33.864 196M / 2G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:37:34.778 328M / 2G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:37:37.608 532M / 2G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:37:43.609 532M / 2G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:37:54.387 532M / 2G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:38:15.440 532M / 2G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:38:56.849 532M / 2G INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:40:29.770 532M / 2G INFO General (binary_converter.hpp : 93) 33554432 reads processed 0:43:33.348 532M / 2G INFO General (binary_converter.hpp : 93) 67108864 reads processed 0:49:44.275 532M / 2G INFO General (binary_converter.hpp : 93) 134217728 reads processed 0:50:17.668 324M / 2G INFO General (binary_converter.hpp : 117) 139945158 reads written 0:50:18.014 8M / 2G INFO General (read_converter.hpp : 87) Converting single reads 0:50:18.185 136M / 2G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:50:18.221 144M / 2G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:50:18.294 152M / 2G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:50:18.438 172M / 2G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:50:18.726 216M / 2G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:50:19.301 296M / 2G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:50:20.539 460M / 2G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:50:22.685 772M / 2G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:50:25.894 1G / 2G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:50:35.732 1G / 2G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:50:52.330 484M / 2G INFO General (binary_converter.hpp : 117) 13472854 reads written 0:50:52.934 8M / 2G INFO General (read_converter.hpp : 95) Converting merged reads 0:50:53.042 136M / 2G INFO General (binary_converter.hpp : 117) 0 reads written 0:50:53.051 8M / 2G INFO General (read_converter.hpp : 77) Converting reads to binary format for library #2 (takes a while) 0:50:53.051 8M / 2G INFO General (read_converter.hpp : 78) Converting paired reads 0:50:53.323 80M / 2G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:50:53.537 88M / 2G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:50:53.677 108M / 2G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:50:53.990 148M / 2G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:50:54.663 228M / 2G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:50:55.940 384M / 2G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:50:59.831 628M / 2G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:51:05.823 628M / 2G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:51:21.708 632M / 2G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:51:51.724 632M / 2G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:52:49.146 632M / 2G INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:54:31.781 372M / 2G INFO General (binary_converter.hpp : 117) 31883074 reads written 0:54:32.133 8M / 2G INFO General (read_converter.hpp : 87) Converting single reads 0:54:32.308 140M / 2G INFO General (binary_converter.hpp : 93) 16384 reads processed 0:54:32.351 148M / 2G INFO General (binary_converter.hpp : 93) 32768 reads processed 0:54:32.453 164M / 2G INFO General (binary_converter.hpp : 93) 65536 reads processed 0:54:32.664 192M / 2G INFO General (binary_converter.hpp : 93) 131072 reads processed 0:54:33.091 252M / 2G INFO General (binary_converter.hpp : 93) 262144 reads processed 0:54:34.019 372M / 2G INFO General (binary_converter.hpp : 93) 524288 reads processed 0:54:35.754 612M / 2G INFO General (binary_converter.hpp : 93) 1048576 reads processed 0:54:39.366 1G / 2G INFO General (binary_converter.hpp : 93) 2097152 reads processed 0:54:47.848 1G / 2G INFO General (binary_converter.hpp : 93) 4194304 reads processed 0:55:08.940 2G / 2G INFO General (binary_converter.hpp : 93) 8388608 reads processed 0:55:51.204 2G / 2G INFO General (binary_converter.hpp : 93) 16777216 reads processed 0:57:15.837 2G / 2G INFO General (binary_converter.hpp : 93) 33554432 reads processed 1:00:00.446 2G / 2G INFO General (binary_converter.hpp : 93) 67108864 reads processed 1:04:51.293 2G / 2G INFO General (binary_converter.hpp : 93) 134217728 reads processed 1:07:31.417 1020M / 2G INFO General (binary_converter.hpp : 117) 170271519 reads written 1:07:33.034 8M / 2G INFO General (read_converter.hpp : 95) Converting merged reads 1:07:33.139 136M / 2G INFO General (binary_converter.hpp : 117) 0 reads written 1:07:33.149 8M / 2G INFO General (construction.cpp : 111) Max read length 391 1:07:33.149 8M / 2G INFO General (construction.cpp : 117) Average read length 125.802 1:07:33.149 8M / 2G INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 1:07:33.155 8M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 1024 files using 32 threads. This might take a while. 1:07:33.157 8M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 65535 1:07:33.157 8M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.552 Gb 1:07:33.157 8M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 1:07:48.761 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 13677801 reads 1:08:01.000 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 27350868 reads 1:08:14.068 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 40599178 reads 1:08:33.226 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 59085538 reads 1:08:42.703 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 69753146 reads 1:09:03.409 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 85166752 reads 1:09:15.210 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 98494920 reads 1:09:27.051 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 109586681 reads 1:09:45.911 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 126683120 reads 1:09:56.019 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 139231864 reads 1:10:09.119 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 153481808 reads 1:10:27.313 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 167572961 reads 1:10:37.316 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 180360412 reads 1:12:14.217 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 277397458 reads 1:16:34.898 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 543213574 reads 1:21:25.180 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 1076393532 reads 1:26:37.267 17G / 18G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 1:26:38.675 132M / 18G INFO General (kmer_splitters.hpp : 308) Used 1813575876 reads 1:26:38.675 132M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 1:26:57.690 132M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 621018647 kmers in total. 1:26:57.690 132M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 1:27:02.203 132M / 18G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 1:27:02.204 132M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 1:27:02.204 132M / 18G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 1:27:02.204 132M / 18G INFO General (file_limit.hpp : 32) Open file limit set to 65535 1:27:02.204 132M / 18G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.55074 Gb 1:27:02.204 132M / 18G INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 1:27:02.771 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 4424075 kmers 1:27:03.886 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 23766902 kmers 1:27:04.916 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 43172239 kmers 1:27:06.039 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 62575801 kmers 1:27:07.219 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 81975593 kmers 1:27:08.388 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 101384128 kmers 1:27:09.502 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 120798080 kmers 1:27:10.695 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 140209836 kmers 1:27:11.908 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 159617784 kmers 1:27:13.210 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 179025274 kmers 1:27:14.333 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 198429138 kmers 1:27:15.471 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 217833862 kmers 1:27:16.597 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 237235089 kmers 1:27:17.753 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 256646003 kmers 1:27:18.982 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 276053216 kmers 1:27:20.179 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 295465746 kmers 1:27:21.346 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 314876077 kmers 1:27:22.488 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 334286385 kmers 1:27:23.658 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 353684689 kmers 1:27:36.003 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 547761733 kmers 1:27:40.340 17G / 18G INFO General (kmer_splitters.hpp : 385) Used 621019671 kmers. 1:27:40.567 132M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 1:27:49.049 132M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 616694987 kmers in total. 1:27:49.049 132M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 1:27:53.725 132M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 1:28:16.386 456M / 18G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 1:28:45.554 456M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 285993972 bytes occupied (3.71002 bits per kmer). 1:28:46.060 1G / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 1:29:15.229 1G / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 1:29:15.234 1G / 18G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 1:29:15.235 1G / 18G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 1:29:15.236 1G / 18G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 1:30:21.250 1G / 18G INFO Early tip clipping (early_simplification.hpp : 184) 109602424 30-mers were removed by early tip clipper 1:30:21.250 1G / 18G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 1:30:21.251 1G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 1:31:01.075 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 27782428 sequences extracted 1:31:19.125 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 1:31:31.582 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 3013 loops collected 1:31:46.103 8G / 18G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 1:31:46.103 8G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 1:31:46.103 8G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 1:32:04.271 9G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 287994198 bytes occupied (3.70996 bits per kmer). 1:32:05.672 11G / 18G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 1:50:11.182 11G / 18G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 1:50:28.307 11G / 18G INFO General (construction.cpp : 464) Processed 32000000 edges 1:50:40.303 11G / 18G INFO General (construction.cpp : 464) Processed 55569613 edges 1:50:42.938 8G / 18G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 1:51:49.891 8G / 18G INFO ThresholdFinder (ec_threshold_finder.hpp : 114) Bucket size: 56 1:51:49.901 8G / 18G INFO General (genomic_info_filler.cpp : 98) Average edge coverage: 171.45 1:51:49.901 8G / 18G INFO General (genomic_info_filler.cpp : 99) Graph threshold: 1618 1:52:03.469 8G / 18G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 171.45 1:52:03.469 8G / 18G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 1:52:03.469 8G / 18G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 1:52:03.476 8G / 18G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 1:52:03.477 8G / 18G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 1:52:03.477 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 1:52:05.622 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 1:52:05.623 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Remover of short poly-AT edges 1:52:05.623 8G / 18G INFO General (simplification.cpp : 76) Removing short polyAT 1:52:51.598 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Remover of short poly-AT edges triggered 565642 times 1:52:51.598 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Short PolyA/T Edges 1:52:53.360 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Short PolyA/T Edges triggered 0 times 1:52:53.361 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:53:02.825 8G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 812130 times 1:53:02.825 8G / 18G INFO General (graph_simplification.hpp : 708) Removing loops and rc loops with erroneous connections 1:54:45.256 8G / 18G INFO ECLoopRemover (erroneous_connection_remov: 408) Loops: accurately removed/deadend removed/other: 10/4772/226 1:54:45.256 8G / 18G INFO ECLoopRemover (erroneous_connection_remov: 409) RC loops: accurately removed/deadend removed/other: 2/379/1086 1:54:45.344 8G / 18G INFO StageManager (stage.cpp : 132) STAGE == Simplification 1:54:45.344 8G / 18G INFO General (simplification.cpp : 357) Graph simplification started 1:54:45.344 8G / 18G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 1:54:45.344 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:54:45.344 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 1:54:45.344 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:54:49.706 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 146523 times 1:54:49.706 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:54:58.834 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 609539 times 1:54:58.834 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:06:02.620 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2587352 times 2:06:02.620 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:06:07.557 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 4263 times 2:06:07.557 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:06:11.875 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 8004 times 2:06:11.875 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:06:12.744 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 895 times 2:06:12.744 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:06:12.756 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 8 times 2:06:12.756 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:06:12.758 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1 times 2:06:12.758 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:06:12.759 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:06:25.476 9G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:10:35.006 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 4217716 times 2:10:35.006 9G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 2:10:35.006 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:10:38.103 9G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 45078 times 2:10:38.103 9G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:10:40.725 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 32380 times 2:10:40.725 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:12:50.068 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 281090 times 2:12:50.069 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:12:50.838 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 98 times 2:12:50.838 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:12:51.328 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:12:51.329 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 10 times 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:12:51.332 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:12:53.658 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:13:05.458 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 215129 times 2:13:05.458 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 2:13:05.458 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:06.945 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 6997 times 2:13:06.945 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:07.876 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 351 times 2:13:07.876 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:30.383 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 33330 times 2:13:30.384 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:30.521 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 2:13:30.521 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:13:30.620 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:13:32.056 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:13:35.254 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 69165 times 2:13:35.254 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 2:13:35.254 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:36.289 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2111 times 2:13:36.289 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:37.079 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 41 times 2:13:37.079 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:47.804 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 11391 times 2:13:47.805 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:47.866 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 2:13:47.866 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:13:47.905 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:13:49.151 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:13:50.528 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 34449 times 2:13:50.528 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 2:13:50.528 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:51.483 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1009 times 2:13:51.483 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:52.246 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 9 times 2:13:52.247 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:59.172 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 5683 times 2:13:59.172 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:13:59.201 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:13:59.201 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:13:59.220 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:13:59.220 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:13:59.220 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:13:59.220 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:00.362 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:01.158 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 20518 times 2:14:01.158 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 2:14:01.158 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:01.957 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 554 times 2:14:01.957 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:02.659 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 3 times 2:14:02.660 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:07.909 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3264 times 2:14:07.909 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:07.925 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:07.925 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:07.935 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:07.935 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:07.935 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:07.935 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:09.005 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:09.494 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 13636 times 2:14:09.494 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 2:14:09.494 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:10.285 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 371 times 2:14:10.286 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:11.027 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 3 times 2:14:11.028 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:15.545 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2096 times 2:14:15.546 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:15.556 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:15.556 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:15.562 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:15.562 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:15.562 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:15.562 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:16.499 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:16.837 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 9822 times 2:14:16.837 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 2:14:16.837 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:17.599 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 238 times 2:14:17.599 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:18.305 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1 times 2:14:18.305 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:21.975 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1422 times 2:14:21.975 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:21.982 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:21.982 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:21.986 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:21.986 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:21.986 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:21.986 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:22.948 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:23.202 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 7392 times 2:14:23.202 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 2:14:23.202 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:23.974 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 186 times 2:14:23.975 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:24.697 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 3 times 2:14:24.697 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:27.988 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1068 times 2:14:27.988 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:27.993 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:27.993 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:27.995 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:27.995 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:27.995 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:27.995 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:28.895 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:29.094 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 5723 times 2:14:29.094 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 2:14:29.094 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:29.845 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 152 times 2:14:29.846 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:30.596 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1 times 2:14:30.597 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:33.800 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 760 times 2:14:33.800 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:33.804 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:33.804 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:33.806 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:33.806 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:33.806 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:33.806 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:34.600 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:34.750 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 4612 times 2:14:34.750 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 2:14:34.750 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:35.469 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 122 times 2:14:35.470 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:36.253 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1 times 2:14:36.254 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:39.345 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 654 times 2:14:39.345 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:39.348 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:39.348 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:39.349 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:39.349 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:39.349 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:39.349 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:40.057 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:40.059 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 30 times 2:14:40.060 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 2:14:40.060 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:40.061 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:40.061 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:40.061 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:40.061 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 4 times 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:40.085 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 2:14:40.085 8G / 18G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 13 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 2:14:40.085 8G / 18G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 2:14:40.085 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 2:14:40.086 8G / 18G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 2:14:40.086 8G / 18G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 2:14:40.086 8G / 18G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 2:14:40.086 8G / 18G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 2:14:40.086 8G / 18G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 2:14:40.086 8G / 18G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 2:14:40.086 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 2:14:42.043 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 39449 times 2:14:42.043 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 2:14:46.700 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 102416 times 2:14:46.700 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 2:15:30.839 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 2863 times 2:15:30.839 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:15:31.871 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 290 times 2:15:31.871 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 2:15:34.200 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 72560 times 2:15:34.200 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:15:36.759 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2838 times 2:15:36.759 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 2:15:38.557 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 2:15:38.557 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 2:15:39.450 8G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 10343 times 2:15:39.450 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 2:15:40.462 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 3253 times 2:15:40.462 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 2:15:41.394 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 351 times 2:15:41.394 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 2:16:24.555 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 85 times 2:16:24.555 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:16:25.841 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 6 times 2:16:25.841 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 2:16:26.596 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 403 times 2:16:26.596 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:16:28.272 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 108 times 2:16:28.272 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 2:16:29.893 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 2:16:29.893 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 2:16:30.785 8G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 84 times 2:16:30.785 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 2:16:30.789 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 19 times 2:16:30.789 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 2:16:31.749 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 28 times 2:16:31.749 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 2:17:14.681 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 1 times 2:17:14.681 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:17:14.690 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:17:14.691 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 2:17:14.695 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 2 times 2:17:14.702 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:17:14.708 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3 times 2:17:14.708 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 2:17:14.710 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 2:17:14.710 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 2:17:14.710 8G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 0 times 2:17:14.710 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 2:17:14.710 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 0 times 2:17:14.710 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 2:17:15.874 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 2:17:15.874 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 2:17:58.964 8G / 18G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 0 times 2:17:58.964 8G / 18G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 2:18:11.682 8G / 18G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 2:18:38.104 6G / 18G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 3493947 times 2:18:38.104 6G / 18G INFO General (simplification.cpp : 470) Counting average coverage 2:18:39.296 6G / 18G INFO General (simplification.cpp : 476) Average coverage = 555.924 2:18:39.296 6G / 18G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 2:18:39.297 6G / 18G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades_alldata/output//K29/simplified_contigs.fasta 2:18:44.430 6G / 18G INFO General (launch.hpp : 151) SPAdes finished 2:18:55.101 128M / 18G INFO General (main.cpp : 109) Assembling time: 2 hours 18 minutes 55 seconds Max read length detected as 391 == Running assembler: K49 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades_alldata/output/K49/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades_alldata/output/K49/configs/mda_mode.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /DATA/markop/Pcitri_rnaspades_alldata/output/K49/configs/rna_mode.info 0:00:00.000 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 245 Gb 0:00:00.000 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from refs/heads/spades_3.13.1, git revision 9a9d54db2ff9abaac718155bf74c12ec9464e8ca 0:00:00.000 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.000 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/DATA/markop/Pcitri_rnaspades_alldata/output/dataset.info) with K=49 0:00:00.000 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 32 0:00:00.000 4M / 4M INFO General (launch.hpp : 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.001 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.004 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.006 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.008 4M / 4M INFO General (construction.cpp : 111) Max read length 391 0:00:00.008 4M / 4M INFO General (construction.cpp : 117) Average read length 125.802 0:00:00.008 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.008 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 1024 files using 32 threads. This might take a while. 0:00:00.009 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 65535 0:00:00.009 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.55204 Gb 0:00:00.009 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 32768 0:00:07.895 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 7971480 reads 0:00:14.772 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 14482628 reads 0:00:21.200 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 21734290 reads 0:00:25.134 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 26357877 reads 0:00:32.219 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 34054493 reads 0:00:33.472 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 35310264 reads 0:00:42.525 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 44793396 reads 0:00:51.433 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 53999060 reads 0:00:57.563 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 60705444 reads 0:01:03.074 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 66687887 reads 0:01:08.184 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 72449787 reads 0:01:13.726 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 78545032 reads 0:02:10.531 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 141999115 reads 0:04:08.197 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 271352186 reads 0:08:16.748 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 542135061 reads 0:10:48.454 17G / 18G INFO General (kmer_splitters.hpp : 289) Processed 1269391433 reads 0:14:50.794 17G / 18G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:15:18.573 132M / 18G INFO General (kmer_splitters.hpp : 308) Used 1813575876 reads 0:15:18.573 132M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:15:42.979 132M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 617444092 kmers in total. 0:15:42.979 132M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:15:51.983 128M / 18G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:15:51.983 128M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:15:51.983 128M / 18G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:15:51.983 128M / 18G INFO General (file_limit.hpp : 32) Open file limit set to 65535 0:15:51.983 128M / 18G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.55078 Gb 0:15:51.983 128M / 18G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:15:52.660 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 5250261 kmers 0:15:53.232 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 11023339 kmers 0:15:53.794 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 16798354 kmers 0:15:54.464 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 24529663 kmers 0:15:55.024 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 30313467 kmers 0:15:55.577 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 36086979 kmers 0:15:56.248 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 43821814 kmers 0:15:56.912 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 49602479 kmers 0:15:57.509 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 55378789 kmers 0:15:58.204 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 63118015 kmers 0:15:58.800 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 68897240 kmers 0:15:59.413 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 74667674 kmers 0:16:00.117 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 82418338 kmers 0:16:00.686 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 88197958 kmers 0:16:01.310 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 93968465 kmers 0:16:01.976 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 101722867 kmers 0:16:02.593 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 107507169 kmers 0:16:06.668 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 140317401 kmers 0:16:20.919 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 275378121 kmers 0:16:48.335 17G / 18G INFO General (kmer_splitters.hpp : 380) Processed 537768180 kmers 0:16:57.415 17G / 18G INFO General (kmer_splitters.hpp : 385) Used 617447164 kmers. 0:16:57.659 132M / 18G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:17:10.880 132M / 18G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 619557437 kmers in total. 0:17:10.881 132M / 18G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:17:20.061 132M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:17:45.180 456M / 18G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:19:45.799 456M / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 287307272 bytes occupied (3.70984 bits per kmer). 0:19:46.300 1G / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:20:16.332 1G / 18G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:20:16.336 1G / 18G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:20:16.384 1G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:21:02.555 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 29257634 sequences extracted 0:21:24.651 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:21:36.857 2G / 18G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 181 loops collected 0:21:56.563 10G / 18G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:21:56.563 10G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:21:56.563 10G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:22:15.216 10G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 286355778 bytes occupied (3.71021 bits per kmer). 0:22:16.662 12G / 18G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:36:51.163 12G / 18G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:37:11.492 12G / 18G INFO General (construction.cpp : 464) Processed 32000000 edges 0:37:26.230 12G / 18G INFO General (construction.cpp : 464) Processed 58515078 edges 0:37:29.090 9G / 18G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:38:27.039 9G / 18G INFO ThresholdFinder (ec_threshold_finder.hpp : 114) Bucket size: 39 0:38:27.043 9G / 18G INFO General (genomic_info_filler.cpp : 98) Average edge coverage: 113.812 0:38:27.043 9G / 18G INFO General (genomic_info_filler.cpp : 99) Graph threshold: 1070 0:38:27.862 9G / 18G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 113.812 0:38:27.862 9G / 18G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:38:27.862 9G / 18G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:38:27.862 9G / 18G INFO General (graph_pack.hpp : 101) Index refill 0:38:27.862 9G / 18G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:38:27.862 9G / 18G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 0:38:27.863 9G / 18G INFO General (file_limit.hpp : 32) Open file limit set to 65535 0:38:27.863 9G / 18G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.45479 Gb 0:38:27.863 9G / 18G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 0:38:46.674 26G / 27G INFO General (edge_index_builders.hpp : 77) Processed 58515078 edges 0:38:46.675 26G / 27G INFO General (edge_index_builders.hpp : 82) Used 58515078 sequences. 0:38:47.608 9G / 27G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:38:52.599 9G / 27G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 617444092 kmers in total. 0:38:52.599 9G / 27G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:39:01.983 9G / 27G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:39:29.459 9G / 27G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:41:26.701 9G / 27G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 286318272 bytes occupied (3.70972 bits per kmer). 0:41:34.686 23G / 27G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:41:59.969 23G / 27G INFO General (edge_index.hpp : 92) Index refilled 0:41:59.971 23G / 27G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:43:04.022 26G / 27G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:44:17.568 26G / 27G INFO General (gap_closer.cpp : 138) Used 47754126 paired reads 0:44:17.568 26G / 27G INFO General (gap_closer.cpp : 140) Merging paired indices 0:44:29.699 23G / 27G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:46:30.754 23G / 27G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 8641 gaps after checking 99864 candidates 0:46:37.744 23G / 27G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:47:36.497 26G / 27G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:48:00.495 26G / 27G INFO General (gap_closer.cpp : 138) Used 139945158 paired reads 0:48:00.495 26G / 27G INFO General (gap_closer.cpp : 140) Merging paired indices 0:48:12.969 23G / 27G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:50:12.357 23G / 27G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 13500 gaps after checking 163550 candidates 0:50:20.626 23G / 27G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:51:20.225 26G / 27G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:51:43.112 26G / 27G INFO General (gap_closer.cpp : 138) Used 31883074 paired reads 0:51:43.112 26G / 27G INFO General (gap_closer.cpp : 140) Merging paired indices 0:51:55.118 23G / 27G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:53:54.990 23G / 27G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 13488 gaps after checking 151850 candidates 0:54:03.249 23G / 27G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:54:04.601 9G / 27G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:54:04.601 9G / 27G INFO General (graph_simplification.hpp : 669) Flanking coverage based disconnection disabled 0:54:04.601 9G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:54:07.371 9G / 27G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:54:07.371 9G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Remover of short poly-AT edges 0:54:07.371 9G / 27G INFO General (simplification.cpp : 76) Removing short polyAT 0:55:01.566 9G / 27G INFO Simplification (parallel_processing.hpp : 167) Remover of short poly-AT edges triggered 136494 times 0:55:01.566 9G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Short PolyA/T Edges 0:55:03.921 9G / 27G INFO Simplification (parallel_processing.hpp : 167) Short PolyA/T Edges triggered 0 times 0:55:03.921 9G / 27G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 0:55:54.413 9G / 27G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 4360105 times 0:55:54.413 9G / 27G INFO General (graph_simplification.hpp : 708) Removing loops and rc loops with erroneous connections 0:57:30.069 9G / 27G INFO ECLoopRemover (erroneous_connection_remov: 408) Loops: accurately removed/deadend removed/other: 17/1578/86 0:57:30.070 9G / 27G INFO ECLoopRemover (erroneous_connection_remov: 409) RC loops: accurately removed/deadend removed/other: 0/145/434 0:57:30.576 9G / 27G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:57:30.576 9G / 27G INFO General (simplification.cpp : 357) Graph simplification started 0:57:30.576 9G / 27G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 0:57:30.576 9G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 0:57:30.576 9G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:57:30.576 9G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:58:42.610 9G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 4468812 times 0:58:42.610 9G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 0:59:00.211 9G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1004507 times 0:59:00.211 9G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:12:51.383 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1605502 times 1:12:51.383 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:12:54.867 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 2828 times 1:12:54.867 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:12:56.727 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 5146 times 1:12:56.728 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:12:57.722 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 686 times 1:12:57.722 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:12:57.729 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 4 times 1:12:57.729 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:12:57.731 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1 times 1:12:57.731 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2 times 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:12:57.732 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:13:02.677 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:14:48.152 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1465614 times 1:14:48.152 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 1:14:48.152 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:14:51.290 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 41549 times 1:14:51.290 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:14:53.747 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 30879 times 1:14:53.747 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:22.655 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 113271 times 1:16:22.656 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:23.052 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 83 times 1:16:23.052 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:23.294 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:16:23.294 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 8 times 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:16:23.303 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:16:25.032 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:16:29.235 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 71200 times 1:16:29.236 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 1:16:29.236 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:30.530 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 6085 times 1:16:30.530 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:31.298 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 774 times 1:16:31.298 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:44.110 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 12180 times 1:16:44.110 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:44.166 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 4 times 1:16:44.166 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:16:44.209 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:16:45.434 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:16:46.578 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 22934 times 1:16:46.578 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 1:16:46.578 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:47.611 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1697 times 1:16:47.611 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:48.374 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 87 times 1:16:48.374 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:54.554 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 4011 times 1:16:54.554 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:54.573 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 1:16:54.573 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:16:54.588 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:16:55.489 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:16:56.014 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 11346 times 1:16:56.015 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 1:16:56.015 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:16:57.001 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 707 times 1:16:57.001 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:16:57.809 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 11 times 1:16:57.809 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:02.261 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1819 times 1:17:02.261 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:02.271 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:02.271 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:02.278 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:02.278 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:02.278 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:02.278 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:03.100 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:03.389 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 6983 times 1:17:03.389 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 1:17:03.389 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:04.137 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 397 times 1:17:04.137 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:04.813 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 6 times 1:17:04.814 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:08.155 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1113 times 1:17:08.155 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:08.162 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:08.162 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:08.166 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:08.166 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:08.166 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:08.166 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:09.197 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:09.401 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 4735 times 1:17:09.401 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 1:17:09.401 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:10.193 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 240 times 1:17:10.193 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:10.929 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 2 times 1:17:10.929 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:13.750 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 694 times 1:17:13.750 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:13.754 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:13.754 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:13.756 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:13.756 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:13.756 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:13.756 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:14.474 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:14.610 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3443 times 1:17:14.610 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 1:17:14.610 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:15.350 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 148 times 1:17:15.351 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:16.059 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 1 times 1:17:16.059 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:19.131 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 514 times 1:17:19.131 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:19.135 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:19.135 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:19.137 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:19.137 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:19.137 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:19.137 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:20.030 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:20.136 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2519 times 1:17:20.136 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 1:17:20.136 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:20.951 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 105 times 1:17:20.952 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:21.660 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:21.661 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:23.994 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 337 times 1:17:23.994 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:23.995 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:23.995 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:23.997 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:23.997 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:23.997 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:23.997 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:24.635 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:24.723 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2081 times 1:17:24.723 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 1:17:24.723 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:25.428 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 76 times 1:17:25.428 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:26.114 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:26.115 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:28.714 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 257 times 1:17:28.714 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:28.716 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:28.716 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:28.717 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:28.717 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:28.717 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:28.717 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:29.548 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:29.624 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1637 times 1:17:29.624 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 1:17:29.624 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:30.390 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 68 times 1:17:30.391 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:31.144 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:31.144 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:33.495 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 217 times 1:17:33.495 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:33.496 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:33.496 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:33.497 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:33.497 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:33.497 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:33.497 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:34.166 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:34.167 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 6 times 1:17:34.168 16G / 27G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 1:17:34.168 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:17:34.168 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:17:34.169 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Dead end clipper 1:17:34.169 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Dead end clipper triggered 0 times 1:17:34.169 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:17:34.170 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:17:34.170 16G / 27G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 1:17:34.170 16G / 27G INFO ConditionParser (graph_simplification.hpp : 188) Creating relative coverage EC condition with threshold 1 1:17:34.171 16G / 27G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 1:17:34.171 16G / 27G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 1:17:34.172 16G / 27G INFO General (graph_pack.hpp : 101) Index refill 1:17:34.172 16G / 27G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 1:17:34.172 16G / 27G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 1:17:34.173 16G / 27G INFO General (file_limit.hpp : 32) Open file limit set to 65535 1:17:34.174 16G / 27G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.3761 Gb 1:17:34.174 16G / 27G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 1:17:42.339 34G / 34G INFO General (edge_index_builders.hpp : 77) Processed 7783244 edges 1:17:42.340 34G / 34G INFO General (edge_index_builders.hpp : 82) Used 7783244 sequences. 1:17:42.856 16G / 34G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 1:17:45.781 16G / 34G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 316973855 kmers in total. 1:17:45.781 16G / 34G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 1:17:50.356 16G / 34G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 1:18:01.506 17G / 34G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 1:18:50.184 17G / 34G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 146996044 bytes occupied (3.70999 bits per kmer). 1:18:56.453 24G / 34G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 1:19:06.749 24G / 34G INFO General (edge_index.hpp : 92) Index refilled 1:19:06.750 24G / 34G INFO General (gap_closer.cpp : 159) Preparing shift maps 1:19:22.000 25G / 34G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 1:20:33.517 25G / 34G INFO General (gap_closer.cpp : 138) Used 47754126 paired reads 1:20:33.518 25G / 34G INFO General (gap_closer.cpp : 140) Merging paired indices 1:20:37.566 24G / 34G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 1:20:55.304 24G / 34G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 2143 gaps after checking 50647 candidates 1:21:00.778 24G / 34G INFO General (gap_closer.cpp : 159) Preparing shift maps 1:21:14.754 25G / 34G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 1:21:42.045 25G / 34G INFO General (gap_closer.cpp : 138) Used 139945158 paired reads 1:21:42.046 25G / 34G INFO General (gap_closer.cpp : 140) Merging paired indices 1:21:45.286 24G / 34G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 1:22:05.397 24G / 34G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 2826 gaps after checking 53611 candidates 1:22:08.627 24G / 34G INFO General (gap_closer.cpp : 159) Preparing shift maps 1:22:26.540 25G / 34G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 1:22:48.976 25G / 34G INFO General (gap_closer.cpp : 138) Used 31883074 paired reads 1:22:48.976 25G / 34G INFO General (gap_closer.cpp : 140) Merging paired indices 1:22:53.359 24G / 34G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 1:23:11.965 24G / 34G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 2110 gaps after checking 137173 candidates 1:23:15.562 24G / 34G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 1:23:15.562 24G / 34G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 1:23:15.562 24G / 34G INFO General (graph_simplification.hpp : 458) Disconnection of relatively low covered edges disabled 1:23:15.562 24G / 34G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 1:23:15.562 24G / 34G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 1:23:15.562 24G / 34G INFO General (graph_simplification.hpp : 641) Creating parallel br instance 1:23:15.562 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 1:23:19.016 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 5655 times 1:23:19.016 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:24:55.420 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 197764 times 1:24:55.420 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 1:25:49.247 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 6256 times 1:25:49.248 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:25:50.496 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 313 times 1:25:50.496 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 1:26:57.095 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 94437 times 1:26:57.095 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:27:07.905 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3699 times 1:27:07.905 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 1:27:09.764 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 1:27:09.764 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:27:10.708 24G / 34G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 1521 times 1:27:10.708 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 1:27:12.369 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 1310 times 1:27:12.369 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:27:13.537 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 261 times 1:27:13.537 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 1:27:47.491 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 295 times 1:27:47.491 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:27:48.561 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 5 times 1:27:48.562 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 1:27:49.566 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 386 times 1:27:49.566 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:27:51.309 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 120 times 1:27:51.309 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 1:27:52.587 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 1:27:52.587 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:27:53.268 24G / 34G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 6 times 1:27:53.269 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 1:27:53.275 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 4 times 1:27:53.275 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:27:53.923 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 3 times 1:27:53.923 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 1:28:25.499 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 4 times 1:28:25.499 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:28:25.503 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:28:25.503 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 1:28:25.509 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 4 times 1:28:25.509 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:28:25.519 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3 times 1:28:25.519 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 1:28:25.521 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 1:28:25.521 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:28:25.521 24G / 34G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 0 times 1:28:25.521 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage EC remover 1:28:25.521 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage EC remover triggered 0 times 1:28:25.521 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Relative coverage component remover 1:28:26.614 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Relative coverage component remover triggered 0 times 1:28:26.615 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Complex bulge remover 1:28:58.845 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Complex bulge remover triggered 0 times 1:28:58.845 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 1:28:58.845 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 1:28:58.845 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final tip clipper 1:28:58.845 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final tip clipper triggered 0 times 1:28:58.845 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 1:28:58.846 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 1:28:58.846 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Final bulge remover 1:28:58.846 24G / 34G INFO Simplification (parallel_processing.hpp : 167) Final bulge remover triggered 0 times 1:28:58.846 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running AT Tips 1:28:58.846 24G / 34G INFO Simplification (parallel_processing.hpp : 167) AT Tips triggered 0 times 1:28:58.846 24G / 34G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 1:29:09.863 24G / 34G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 1:31:46.630 23G / 34G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 2632468 times 1:31:46.631 23G / 34G INFO General (simplification.cpp : 470) Counting average coverage 1:31:48.561 23G / 34G INFO General (simplification.cpp : 476) Average coverage = 439.681 1:31:48.561 23G / 34G INFO StageManager (stage.cpp : 132) STAGE == Mismatch Correction 1:31:48.561 23G / 34G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 177776507 kmers to process 1:35:02.538 23G / 34G INFO General (graph_pack.hpp : 111) Normalizing done 2:14:51.311 111G / 111G INFO General (mismatch_shall_not_pass.hp: 189) Finished collecting potential mismatches positions 2:21:00.735 26G / 111G INFO General (mismatch_shall_not_pass.hp: 290) All edges processed 2:21:09.670 23G / 111G INFO General (mismatch_correction.cpp : 27) Corrected 19398 nucleotides 2:21:09.675 23G / 111G INFO StageManager (stage.cpp : 132) STAGE == Strand-specific Edge Spliting 2:21:09.675 23G / 111G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 178881615 kmers to process 2:24:09.284 23G / 111G INFO General (graph_pack.hpp : 111) Normalizing done 2:24:09.284 23G / 111G INFO General (ss_edge_split.cpp : 38) Running strand-specific edge splitter only for library # 0 2:24:11.029 23G / 111G INFO General (ss_edge_split.cpp : 46) Selecting usual mapper 2:24:41.246 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:24:41.403 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:24:41.516 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:24:41.625 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:24:41.734 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:24:41.846 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:24:42.483 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:24:43.999 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:24:48.529 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:24:58.630 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:25:17.737 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:25:52.651 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 2:26:59.913 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 134400000 reads 2:29:13.330 24G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 268600000 reads 2:30:57.835 24G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 379387101 reads processed 2:30:59.548 17G / 111G INFO SSCoverage (ss_coverage.hpp : 292) Detecting split positions 2:30:59.652 17G / 111G INFO SSCoverage (ss_coverage.hpp : 302) Splitting edges 2:30:59.688 17G / 111G INFO SSCoverage (ss_coverage.hpp : 306) Total edges splits performed 2166 2:31:03.182 16G / 111G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 2:31:03.188 16G / 111G INFO General (contig_output_stage.cpp : 45) Writing GFA to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/assembly_graph_with_scaffolds.gfa 2:31:08.138 16G / 111G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/before_rr.fasta 2:31:12.935 16G / 111G INFO General (contig_output_stage.cpp : 56) Outputting FastG graph to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/assembly_graph.fastg 2:31:27.181 16G / 111G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/final_contigs.fasta 2:31:31.539 16G / 111G INFO StageManager (stage.cpp : 132) STAGE == Paired Information Counting 2:31:45.894 16G / 111G INFO General (graph_pack.hpp : 101) Index refill 2:31:45.894 16G / 111G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 2:31:45.894 16G / 111G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 512 files using 32 threads. This might take a while. 2:31:45.895 16G / 111G INFO General (file_limit.hpp : 32) Open file limit set to 65535 2:31:45.895 16G / 111G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 2.38037 Gb 2:31:45.895 16G / 111G INFO General (kmer_splitters.hpp : 97) Using cell size of 65536 2:31:49.809 34G / 111G INFO General (edge_index_builders.hpp : 77) Processed 1208220 edges 2:31:49.809 34G / 111G INFO General (edge_index_builders.hpp : 82) Used 1208220 sequences. 2:31:50.111 16G / 111G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 2:31:52.204 16G / 111G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 157521861 kmers in total. 2:31:52.204 16G / 111G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 2:31:54.565 16G / 111G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 2:32:00.091 16G / 111G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 2:32:14.523 16G / 111G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 73051112 bytes occupied (3.71002 bits per kmer). 2:32:17.126 20G / 111G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 2:32:22.161 20G / 111G INFO General (edge_index.hpp : 92) Index refilled 2:32:22.161 20G / 111G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 178881615 kmers to process 2:32:22.161 20G / 111G INFO General (graph_pack.hpp : 111) Normalizing done 2:32:22.892 20G / 111G INFO General (pair_info_count.cpp : 323) Min edge length for estimation: 719 2:32:22.892 20G / 111G INFO General (pair_info_count.cpp : 334) Estimating insert size for library #0 2:32:22.892 20G / 111G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 2:32:23.253 20G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:32:33.704 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:32:33.774 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:32:33.836 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:32:33.898 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:32:33.961 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:32:33.999 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:32:34.290 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:32:34.784 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:32:44.572 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:32:55.891 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:33:25.587 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:33:45.409 20G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 47754126 reads processed 2:33:47.007 20G / 111G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 2:33:47.007 20G / 111G INFO General (pair_info_count.cpp : 213) 7722858 paired reads (16.1721% of all) aligned to long edges 2:33:47.050 20G / 111G INFO General (pair_info_count.cpp : 357) Insert size = 385.829, deviation = 124.99, left quantile = 199, right quantile = 530, read length = 391 2:33:47.050 20G / 111G WARN General (pair_info_count.cpp : 361) Estimated mean insert size 385.829 is very small compared to read length 391 2:33:47.050 20G / 111G INFO General (pair_info_count.cpp : 386) Mapping library #0 2:33:47.050 20G / 111G INFO General (pair_info_count.cpp : 388) Mapping paired reads (takes a while) 2:33:47.050 20G / 111G INFO General (pair_info_count.cpp : 289) Left insert size quantile 199, right insert size quantile 530, filtering threshold 0, rounding threshold 0 2:33:47.059 20G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:34:20.946 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:34:20.950 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:34:21.024 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:34:21.037 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:34:21.079 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:34:21.233 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:34:21.991 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:34:23.661 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:34:54.279 20G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:35:37.538 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:38:11.000 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:39:49.507 21G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 47754126 reads processed 2:39:49.795 21G / 111G INFO General (pair_info_count.cpp : 395) Mapping single reads of library #0 2:39:49.795 21G / 111G INFO General (pair_info_count.cpp : 255) Will calculate lib coverage as well 2:39:49.795 21G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:39:56.007 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:39:56.024 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:39:56.040 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:39:56.054 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:39:56.072 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:39:56.084 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:39:56.151 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:39:56.355 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:40:02.515 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:40:09.115 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:40:28.028 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:41:00.060 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 2:42:03.243 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 134400000 reads 2:44:15.692 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 268600000 reads 2:45:52.994 21G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 379387101 reads processed 2:45:53.245 21G / 111G INFO General (pair_info_count.cpp : 397) Total paths obtained from single reads: 0 2:45:53.245 21G / 111G INFO General (pair_info_count.cpp : 334) Estimating insert size for library #1 2:45:53.245 21G / 111G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 2:45:53.607 22G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:45:57.623 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:45:57.670 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:45:57.704 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:45:57.750 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:45:57.799 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:45:57.835 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:45:58.083 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:45:58.499 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:46:01.083 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:46:05.769 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:46:15.784 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:46:35.504 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 2:47:13.722 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 134400000 reads 2:47:17.192 22G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 139945158 reads processed 2:47:18.804 22G / 111G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 2:47:18.804 22G / 111G INFO General (pair_info_count.cpp : 213) 23517933 paired reads (16.8051% of all) aligned to long edges 2:47:18.857 21G / 111G INFO General (pair_info_count.cpp : 357) Insert size = 164.579, deviation = 46.9004, left quantile = 113, right quantile = 228, read length = 91 2:47:18.857 21G / 111G INFO General (pair_info_count.cpp : 386) Mapping library #1 2:47:18.857 21G / 111G INFO General (pair_info_count.cpp : 388) Mapping paired reads (takes a while) 2:47:18.857 21G / 111G INFO General (pair_info_count.cpp : 289) Left insert size quantile 113, right insert size quantile 228, filtering threshold 0, rounding threshold 0 2:47:18.866 21G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:47:23.217 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:47:23.218 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:47:23.218 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:47:23.218 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:47:23.218 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:47:23.219 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:47:23.219 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:47:23.220 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:47:27.491 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:47:31.635 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:47:44.483 21G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:48:05.421 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 2:48:46.450 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 134400000 reads 2:48:49.788 22G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 139945158 reads processed 2:48:50.026 22G / 111G INFO General (pair_info_count.cpp : 395) Mapping single reads of library #1 2:48:50.026 22G / 111G INFO General (pair_info_count.cpp : 255) Will calculate lib coverage as well 2:48:50.026 22G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:48:53.877 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:48:53.900 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:48:53.923 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:48:53.945 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:48:53.967 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:48:53.985 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:48:54.137 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:48:54.441 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:48:57.479 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:49:02.016 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:49:13.031 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:49:33.056 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 2:50:12.890 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 134400000 reads 2:51:34.426 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 268600000 reads 2:51:49.346 22G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 293363170 reads processed 2:51:49.567 22G / 111G INFO General (pair_info_count.cpp : 397) Total paths obtained from single reads: 0 2:51:49.567 22G / 111G INFO General (pair_info_count.cpp : 334) Estimating insert size for library #2 2:51:49.567 22G / 111G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 2:51:49.955 22G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:51:54.982 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:51:55.040 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:51:55.096 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:51:55.135 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:51:55.168 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:51:55.193 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:51:55.361 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:51:55.873 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:52:00.387 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:52:06.245 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:52:18.024 22G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 31883074 reads processed 2:52:19.627 22G / 111G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 2:52:19.628 22G / 111G INFO General (pair_info_count.cpp : 213) 5781026 paired reads (18.132% of all) aligned to long edges 2:52:19.671 22G / 111G INFO General (pair_info_count.cpp : 357) Insert size = 251.904, deviation = 63.6816, left quantile = 165, right quantile = 326, read length = 241 2:52:19.671 22G / 111G WARN General (pair_info_count.cpp : 361) Estimated mean insert size 251.904 is very small compared to read length 241 2:52:19.671 22G / 111G INFO General (pair_info_count.cpp : 386) Mapping library #2 2:52:19.671 22G / 111G INFO General (pair_info_count.cpp : 388) Mapping paired reads (takes a while) 2:52:19.671 22G / 111G INFO General (pair_info_count.cpp : 289) Left insert size quantile 165, right insert size quantile 326, filtering threshold 0, rounding threshold 0 2:52:19.681 22G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:52:25.240 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:52:25.246 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:52:25.248 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:52:25.254 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:52:25.254 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:52:25.261 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:52:25.270 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:52:25.370 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:52:30.908 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:52:36.744 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:52:48.774 22G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 31883074 reads processed 2:52:49.035 22G / 111G INFO General (pair_info_count.cpp : 395) Mapping single reads of library #2 2:52:49.035 22G / 111G INFO General (pair_info_count.cpp : 255) Will calculate lib coverage as well 2:52:49.035 22G / 111G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 2:52:54.159 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 200000 reads 2:52:54.189 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 400000 reads 2:52:54.213 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 600000 reads 2:52:54.224 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 800000 reads 2:52:54.237 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1000000 reads 2:52:54.255 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 1200000 reads 2:52:54.352 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 2200000 reads 2:52:54.576 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 4200000 reads 2:52:59.413 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 8400000 reads 2:53:04.876 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 16800000 reads 2:53:19.945 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 33600000 reads 2:53:45.948 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 67200000 reads 2:54:37.827 22G / 111G INFO General (sequence_mapper_notifier.h: 80) Processed 134400000 reads 2:55:41.679 22G / 111G INFO General (sequence_mapper_notifier.h: 98) Total 234037667 reads processed 2:55:41.795 22G / 111G INFO General (pair_info_count.cpp : 397) Total paths obtained from single reads: 0 2:55:41.795 22G / 111G INFO StageManager (stage.cpp : 132) STAGE == Distance Estimation 2:55:41.795 22G / 111G INFO General (distance_estimation.cpp : 173) Processing library #0 2:55:41.795 22G / 111G INFO General (distance_estimation.cpp : 149) Weight Filter Done 2:55:41.801 22G / 111G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 2:59:24.697 23G / 111G INFO General (distance_estimation.cpp : 34) Filtering info 2:59:24.697 23G / 111G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 68682816 2:59:51.290 23G / 111G INFO General (pair_info_filters.hpp : 263) Done filtering 2:59:51.306 23G / 111G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 2:59:53.915 23G / 111G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 2:59:53.915 23G / 111G INFO General (distance_estimation.cpp : 160) Improving paired information 3:00:31.518 23G / 111G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 2380516; contradictional = 302 3:01:26.480 24G / 111G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 700447; contradictional = 12 3:01:26.480 24G / 111G INFO General (distance_estimation.cpp : 173) Processing library #1 3:01:26.480 24G / 111G INFO General (distance_estimation.cpp : 149) Weight Filter Done 3:01:26.480 24G / 111G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 3:01:32.523 24G / 111G INFO General (distance_estimation.cpp : 34) Filtering info 3:01:32.523 24G / 111G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2285798 3:01:34.960 24G / 111G INFO General (pair_info_filters.hpp : 263) Done filtering 3:01:34.964 24G / 111G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 3:01:35.527 24G / 111G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 3:01:35.527 24G / 111G INFO General (distance_estimation.cpp : 160) Improving paired information 3:01:40.677 24G / 111G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 206158; contradictional = 62 3:01:49.580 24G / 111G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 142882; contradictional = 0 3:01:49.580 24G / 111G INFO General (distance_estimation.cpp : 173) Processing library #2 3:01:49.580 24G / 111G INFO General (distance_estimation.cpp : 149) Weight Filter Done 3:01:49.580 24G / 111G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 3:02:11.669 24G / 111G INFO General (distance_estimation.cpp : 34) Filtering info 3:02:11.669 24G / 111G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 4895127 3:02:15.318 24G / 111G INFO General (pair_info_filters.hpp : 263) Done filtering 3:02:15.324 24G / 111G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 3:02:16.132 24G / 111G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 3:02:16.132 24G / 111G INFO General (distance_estimation.cpp : 160) Improving paired information 3:02:27.481 24G / 111G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 643408; contradictional = 92 3:02:42.495 24G / 111G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 212163; contradictional = 8 3:02:42.495 24G / 111G INFO StageManager (stage.cpp : 132) STAGE == Repeat Resolving 3:05:09.145 24G / 111G INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving 3:05:09.151 24G / 111G INFO General (launcher.cpp : 481) ExSPAnder repeat resolving tool started 3:05:14.507 26G / 111G INFO General (launcher.cpp : 392) Creating main extenders, unique edge length = 2000 3:05:18.406 26G / 111G INFO General (extenders_logic.cpp : 475) Using 3 paired-end libraries 3:05:18.406 26G / 111G INFO General (extenders_logic.cpp : 476) Using 3 paired-end scaffolding libraries 3:05:18.406 26G / 111G INFO General (extenders_logic.cpp : 477) Using 0 single read libraries 3:05:18.406 26G / 111G INFO General (launcher.cpp : 420) Total number of extenders is 15 3:05:18.406 26G / 111G INFO General (path_extender.hpp : 885) Processed 0 paths from 600043 (0%) 3:05:19.079 26G / 111G INFO General (path_extender.hpp : 883) Processed 128 paths from 600043 (0%) 3:05:19.606 26G / 111G INFO General (path_extender.hpp : 883) Processed 256 paths from 600043 (0%) 3:05:20.669 26G / 111G INFO General (path_extender.hpp : 883) Processed 512 paths from 600043 (0%) 3:05:23.579 26G / 111G INFO General (path_extender.hpp : 883) Processed 1024 paths from 600043 (0%) 3:05:27.602 26G / 111G INFO General (path_extender.hpp : 883) Processed 2048 paths from 600043 (0%) 3:05:35.313 26G / 111G INFO General (path_extender.hpp : 883) Processed 4096 paths from 600043 (0%) 3:05:55.294 26G / 111G INFO General (path_extender.hpp : 883) Processed 8192 paths from 600043 (1%) 3:06:17.254 26G / 111G INFO General (path_extender.hpp : 883) Processed 16384 paths from 600043 (2%) 3:06:55.726 27G / 111G INFO General (path_extender.hpp : 883) Processed 32768 paths from 600043 (5%) 3:07:43.416 27G / 111G INFO General (path_extender.hpp : 885) Processed 60005 paths from 600043 (10%) 3:07:51.560 27G / 111G INFO General (path_extender.hpp : 883) Processed 65536 paths from 600043 (10%) 3:09:00.077 28G / 111G INFO General (path_extender.hpp : 885) Processed 120010 paths from 600043 (20%) 3:09:16.610 28G / 111G INFO General (path_extender.hpp : 883) Processed 131072 paths from 600043 (21%) 3:10:55.450 28G / 111G INFO General (path_extender.hpp : 885) Processed 180015 paths from 600043 (30%) 3:13:30.211 29G / 111G INFO General (path_extender.hpp : 885) Processed 240020 paths from 600043 (40%) 3:14:11.048 29G / 111G INFO General (path_extender.hpp : 883) Processed 262144 paths from 600043 (43%) 3:15:17.886 30G / 111G INFO General (path_extender.hpp : 885) Processed 300025 paths from 600043 (50%) 3:16:52.474 30G / 111G INFO General (path_extender.hpp : 885) Processed 360030 paths from 600043 (60%) 3:17:46.774 30G / 111G INFO General (path_extender.hpp : 885) Processed 420035 paths from 600043 (70%) 3:18:53.876 31G / 111G INFO General (path_extender.hpp : 885) Processed 480040 paths from 600043 (80%) 3:19:10.085 31G / 111G INFO General (path_extender.hpp : 883) Processed 524288 paths from 600043 (87%) 3:19:18.143 31G / 111G INFO General (path_extender.hpp : 885) Processed 540045 paths from 600043 (90%) 3:19:31.551 31G / 111G INFO General (launcher.cpp : 234) Finalizing paths 3:19:31.551 31G / 111G INFO General (launcher.cpp : 236) Deduplicating paths 3:19:36.958 31G / 111G INFO General (launcher.cpp : 240) Paths deduplicated 3:19:36.958 31G / 111G INFO General (launcher.cpp : 247) Overlaps will not be removed 3:19:39.418 31G / 111G INFO General (launcher.cpp : 257) Paths finalized 3:19:39.418 31G / 111G INFO General (launcher.cpp : 427) Closing gaps in paths 3:19:41.859 31G / 111G INFO General (launcher.cpp : 455) Gap closing completed 3:19:43.671 31G / 111G INFO General (launcher.cpp : 286) Traversing tandem repeats 3:19:49.600 31G / 111G INFO General (launcher.cpp : 296) Traversed 67 loops 3:19:49.600 31G / 111G INFO General (launcher.cpp : 234) Finalizing paths 3:19:49.600 31G / 111G INFO General (launcher.cpp : 236) Deduplicating paths 3:19:52.449 31G / 111G INFO General (launcher.cpp : 240) Paths deduplicated 3:19:52.449 31G / 111G INFO General (launcher.cpp : 247) Overlaps will not be removed 3:19:53.755 31G / 111G INFO General (launcher.cpp : 257) Paths finalized 3:19:53.755 31G / 111G INFO General (launcher.cpp : 525) Paths will be printed according to strand-specific coverage 3:19:54.543 31G / 111G INFO General (launcher.cpp : 466) Finalizing paths - hard 3:19:55.460 33G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 1.5 converted to 537 3:19:55.460 33G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 130 bp converted to 537 3:19:55.460 33G / 111G INFO General (launcher.cpp : 281) Length cutoff: 537 3:19:55.628 32G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 2 converted to 733 3:19:55.628 32G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 180 bp converted to 733 3:19:55.628 32G / 111G INFO General (launcher.cpp : 281) Length cutoff: 733 3:19:55.661 32G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 2 converted to 733 3:19:55.661 32G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 180 bp converted to 733 3:19:55.661 32G / 111G INFO General (launcher.cpp : 281) Length cutoff: 733 3:20:03.756 31G / 111G INFO General (launcher.cpp : 466) Finalizing paths - soft 3:20:04.662 33G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 1.05 converted to 361 3:20:04.662 33G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 85 bp converted to 361 3:20:04.662 33G / 111G INFO General (launcher.cpp : 281) Length cutoff: 361 3:20:04.811 32G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 1.5 converted to 537 3:20:04.811 32G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 130 bp converted to 537 3:20:04.811 32G / 111G INFO General (launcher.cpp : 281) Length cutoff: 537 3:20:04.854 32G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 1.2 converted to 420 3:20:04.854 32G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 100 bp converted to 420 3:20:04.854 32G / 111G INFO General (launcher.cpp : 281) Length cutoff: 420 3:20:13.945 31G / 111G INFO General (launcher.cpp : 474) Finalizing main paths 3:20:13.945 31G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 1.3 converted to 459 3:20:13.945 31G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 110 bp converted to 459 3:20:13.945 31G / 111G INFO General (launcher.cpp : 281) Length cutoff: 459 3:20:14.125 31G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 1.6 converted to 576 3:20:14.125 31G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 140 bp converted to 576 3:20:14.125 31G / 111G INFO General (launcher.cpp : 281) Length cutoff: 576 3:20:14.173 31G / 111G INFO General (launcher.cpp : 279) Read length relative cutoff 1.5 converted to 537 3:20:14.173 31G / 111G INFO General (launcher.cpp : 280) Read length absolute cutoff 130 bp converted to 537 3:20:14.173 31G / 111G INFO General (launcher.cpp : 281) Length cutoff: 537 3:20:14.374 31G / 111G INFO General (launcher.cpp : 534) ExSPAnder repeat resolving tool finished 3:20:29.160 25G / 111G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 3:20:29.161 25G / 111G INFO General (contig_output_stage.cpp : 45) Writing GFA to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/assembly_graph_with_scaffolds.gfa 3:20:33.657 25G / 111G INFO General (contig_output.hpp : 22) Outputting contigs to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/before_rr.fasta 3:20:38.353 25G / 111G INFO General (contig_output_stage.cpp : 56) Outputting FastG graph to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/assembly_graph.fastg 3:20:52.899 25G / 111G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /DATA/markop/Pcitri_rnaspades_alldata/output//K49/transcripts.paths 3:21:04.766 25G / 111G INFO General (launch.hpp : 151) SPAdes finished 3:23:29.819 208M / 111G INFO General (main.cpp : 109) Assembling time: 3 hours 23 minutes 29 seconds ===== Assembling finished. Used k-mer sizes: 29, 49 * Assembled transcripts are in /DATA/markop/Pcitri_rnaspades_alldata/output/transcripts.fasta * Paths in the assembly graph corresponding to the transcripts are in /DATA/markop/Pcitri_rnaspades_alldata/output/transcripts.paths * Hard filtered transcripts are in /DATA/markop/Pcitri_rnaspades_alldata/output/hard_filtered_transcripts.fasta * Soft filtered transcripts are in /DATA/markop/Pcitri_rnaspades_alldata/output/soft_filtered_transcripts.fasta * Assembly graph is in /DATA/markop/Pcitri_rnaspades_alldata/output/assembly_graph.fastg * Assembly graph in GFA format is in /DATA/markop/Pcitri_rnaspades_alldata/output/assembly_graph_with_scaffolds.gfa ======= SPAdes pipeline finished WITH WARNINGS! === Error correction and assembling warnings: * 2:33:47.050 20G / 111G WARN General (pair_info_count.cpp : 361) Estimated mean insert size 385.829 is very small compared to read length 391 * 2:52:19.671 22G / 111G WARN General (pair_info_count.cpp : 361) Estimated mean insert size 251.904 is very small compared to read length 241 ======= Warnings saved to /DATA/markop/Pcitri_rnaspades_alldata/output/warnings.log SPAdes log can be found here: /DATA/markop/Pcitri_rnaspades_alldata/output/spades.log Thank you for using SPAdes!