Mercurial > repos > iuc > shovill
comparison test-data/shovill_std_log @ 8:ad80238462c1 draft
planemo upload for repository https://github.com/galaxyproject/tools-iuc/tree/master/tools/shovill commit 1e28eb4ffcf3d9168877c291d27e533b96021445
| author | iuc |
|---|---|
| date | Fri, 16 Sep 2022 14:39:43 +0000 |
| parents | |
| children |
comparison
equal
deleted
inserted
replaced
| 7:2a9baa0c4316 | 8:ad80238462c1 |
|---|---|
| 1 [shovill] Hello piemari | |
| 2 [shovill] You ran: /home/piemari/apps/conda/envs/metaphlan/bin/shovill --outdir ../shovill_bam/ --cpus 8 --ram 4 --R1 ../mutant_R1.fastq --R2 ../mutant_R2.fastq --namefmt contig%05d --depth 100 --keepfiles --minlen 0 --mincov 2 --assembler spades --force | |
| 3 [shovill] This is shovill 1.1.0 | |
| 4 [shovill] Written by Torsten Seemann | |
| 5 [shovill] Homepage is https://github.com/tseemann/shovill | |
| 6 [shovill] Operating system is linux | |
| 7 [shovill] Perl version is v5.32.1 | |
| 8 [shovill] Machine has 32 CPU cores and 251.66 GB RAM | |
| 9 [shovill] Using bwa - /home/piemari/apps/conda/envs/metaphlan/bin/bwa | Version: 0.7.17-r1188 | |
| 10 [shovill] Using flash - /home/piemari/apps/conda/envs/metaphlan/bin/flash | FLASH v1.2.11 | |
| 11 [shovill] Using java - /home/piemari/apps/conda/envs/metaphlan/bin/java | openjdk version "11.0.1" 2018-10-16 LTS | |
| 12 [shovill] Using kmc - /home/piemari/apps/conda/envs/metaphlan/bin/kmc | K-Mer Counter (KMC) ver. 3.2.1 (2022-01-04) | |
| 13 [shovill] Using lighter - /home/piemari/apps/conda/envs/metaphlan/bin/lighter | Lighter v1.1.2 | |
| 14 [shovill] Using megahit - /home/piemari/apps/conda/envs/metaphlan/bin/megahit | MEGAHIT v1.2.9 | |
| 15 [shovill] Using megahit_toolkit - /home/piemari/apps/conda/envs/metaphlan/bin/megahit_toolkit | v1.2.9 | |
| 16 [shovill] Using pigz - /home/piemari/apps/conda/envs/metaphlan/bin/pigz | pigz 2.6 | |
| 17 [shovill] Using pilon - /home/piemari/apps/conda/envs/metaphlan/bin/pilon | Pilon version 1.24 Thu Jan 28 13:00:45 2021 -0500 | |
| 18 [shovill] Using samclip - /home/piemari/apps/conda/envs/metaphlan/bin/samclip | samclip 0.4.0 | |
| 19 [shovill] Using samtools - /home/piemari/apps/conda/envs/metaphlan/bin/samtools | Version: 1.15 (using htslib 1.14) | |
| 20 [shovill] Using seqtk - /home/piemari/apps/conda/envs/metaphlan/bin/seqtk | Version: 1.3-r106 | |
| 21 [shovill] Using skesa - /home/piemari/apps/conda/envs/metaphlan/bin/skesa | SKESA 2.4.0 | |
| 22 [shovill] Using spades.py - /home/piemari/apps/conda/envs/metaphlan/bin/spades.py | SPAdes genome assembler v3.14.1 | |
| 23 [shovill] Using trimmomatic - /home/piemari/apps/conda/envs/metaphlan/bin/trimmomatic | 0.39 | |
| 24 [shovill] Using velvetg - /home/piemari/apps/conda/envs/metaphlan/bin/velvetg | Version 1.2.10 | |
| 25 [shovill] Using velveth - /home/piemari/apps/conda/envs/metaphlan/bin/velveth | Version 1.2.10 | |
| 26 [shovill] Found spades version: 003014000 | |
| 27 [shovill] Will use spades 003014000 options: --isolate and --merged | |
| 28 [shovill] Forced overwrite of existing --outdir ../shovill_bam/ | |
| 29 [shovill] Using tempdir: /tmp | |
| 30 [shovill] Changing into folder: /home/piemari/shovill_bam | |
| 31 [shovill] Collecting raw read statistics with 'seqtk' | |
| 32 [shovill] Running: seqtk fqchk -q3 \/home\/piemari\/mutant_R1\.fastq >/tmp/1MILzK1fer 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log | |
| 33 [shovill] Read stats: max_len = 150 | |
| 34 [shovill] Read stats: min_len = 150 | |
| 35 [shovill] Read stats: total_bp = 300000 | |
| 36 [shovill] Read stats: avg_len = 150 | |
| 37 [shovill] Estimating genome size by counting unqiue 21-mers > frequency 10 | |
| 38 [shovill] Running: kmc -sm -m2 -t8 -k21 -ci10 \/home\/piemari\/mutant_R1\.fastq /tmp/_n_4cOtiee/kmc /tmp/_n_4cOtiee 2>&1 | sed 's/^/[kmc] /' | tee -a shovill.log | |
| 39 [kmc] ** | |
| 40 [kmc] | |
| 41 Stage 1: 0% | |
| 42 Stage 1: 100% | |
| 43 [kmc] | |
| 44 Stage 2: 0% | |
| 45 Stage 2: 84% | |
| 46 Stage 2: 90% | |
| 47 Stage 2: 94% | |
| 48 Stage 2: 96% | |
| 49 Stage 2: 98% | |
| 50 Stage 2: 99% | |
| 51 Stage 2: 100% | |
| 52 [kmc] | |
| 53 [kmc] | |
| 54 [kmc] 1st stage: 0.08264s | |
| 55 [kmc] 2nd stage: 0.104849s | |
| 56 [kmc] 3rd stage: 0.002521s | |
| 57 [kmc] Total : 0.19001s | |
| 58 [kmc] Tmp size : 0MB | |
| 59 [kmc] Tmp size strict memory : 0MB | |
| 60 [kmc] Tmp total: 0MB | |
| 61 [kmc] | |
| 62 [kmc] Stats: | |
| 63 [kmc] No. of k-mers below min. threshold : 34495 | |
| 64 [kmc] No. of k-mers above max. threshold : 0 | |
| 65 [kmc] No. of unique k-mers : 35683 | |
| 66 [kmc] No. of unique counted k-mers : 1188 | |
| 67 [kmc] Total no. of k-mers : 130000 | |
| 68 [kmc] Total no. of reads : 1000 | |
| 69 [kmc] Total no. of super-k-mers : 18576 | |
| 70 [shovill] Using genome size 1188 bp | |
| 71 [shovill] Estimated sequencing depth: 252 x | |
| 72 [shovill] Subsampling reads by factor 0.397 to get from 252x to 100x | |
| 73 [shovill] Running: seqtk sample \/home\/piemari\/mutant_R1\.fastq 0.397 | pigz --fast -c -p 8 > R1.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log | |
| 74 [shovill] Running: seqtk sample \/home\/piemari\/mutant_R2\.fastq 0.397 | pigz --fast -c -p 8 > R2.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log | |
| 75 [shovill] Appending -Xmx4g to _JAVA_OPTIONS | |
| 76 [shovill] Running: ln -sf R1\.sub\.fq\.gz R1.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log | |
| 77 [shovill] Running: ln -sf R2\.sub\.fq\.gz R2.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log | |
| 78 [shovill] Average read length looks like 150 bp | |
| 79 [shovill] Automatically setting --minlen to 75 | |
| 80 [shovill] Setting k-mer range to (31 .. 112) | |
| 81 [shovill] Estimated K-mers: 31 51 71 91 111 [kn=5, ks=20, kmin=31, kmax=112] | |
| 82 [shovill] Using kmers: 31,51,71,91,111 | |
| 83 [shovill] Correcting reads with 'Lighter' | |
| 84 [shovill] Running: lighter -od . -r R1.fq.gz -r R2.fq.gz -K 32 1188 -t 8 -maxcor 1 2>&1 | sed 's/^/[lighter] /' | tee -a shovill.log | |
| 85 [lighter] [2022-05-04 12:29:31] =============Start==================== | |
| 86 [lighter] [2022-05-04 12:29:31] Scanning the input files to infer alpha(sampling rate) | |
| 87 [lighter] [2022-05-04 12:29:31] Average coverage is 103.535 and alpha is 0.068 | |
| 88 [lighter] [2022-05-04 12:29:31] Bad quality threshold is "1" | |
| 89 [lighter] [2022-05-04 12:29:32] Finish sampling kmers | |
| 90 [lighter] [2022-05-04 12:29:32] Bloom filter A's false positive rate: 0.264464 | |
| 91 [lighter] [2022-05-04 12:29:32] Finish storing trusted kmers | |
| 92 [lighter] [2022-05-04 12:29:32] Finish error correction | |
| 93 [lighter] Processed 820 reads: | |
| 94 [lighter] 48 are error-free | |
| 95 [lighter] Corrected 1731 bases(2.242228 corrections for reads with errors) | |
| 96 [lighter] Trimmed 0 reads with average trimmed bases 0.000000 | |
| 97 [lighter] Discard 0 reads | |
| 98 [shovill] Overlapping/stitching PE reads with 'FLASH' | |
| 99 [shovill] Running: flash -m 20 -M 150 -d . -o flash -z -t 8 R1.cor.fq.gz R2.cor.fq.gz 2>&1 | sed 's/^//' | tee -a shovill.log | |
| 100 [FLASH] Starting FLASH v1.2.11 | |
| 101 [FLASH] Fast Length Adjustment of SHort reads | |
| 102 [FLASH] | |
| 103 [FLASH] Input files: | |
| 104 [FLASH] R1.cor.fq.gz | |
| 105 [FLASH] R2.cor.fq.gz | |
| 106 [FLASH] | |
| 107 [FLASH] Output files: | |
| 108 [FLASH] ./flash.extendedFrags.fastq.gz | |
| 109 [FLASH] ./flash.notCombined_1.fastq.gz | |
| 110 [FLASH] ./flash.notCombined_2.fastq.gz | |
| 111 [FLASH] ./flash.hist | |
| 112 [FLASH] ./flash.histogram | |
| 113 [FLASH] | |
| 114 [FLASH] Parameters: | |
| 115 [FLASH] Min overlap: 20 | |
| 116 [FLASH] Max overlap: 150 | |
| 117 [FLASH] Max mismatch density: 0.250000 | |
| 118 [FLASH] Allow "outie" pairs: false | |
| 119 [FLASH] Cap mismatch quals: false | |
| 120 [FLASH] Combiner threads: 8 | |
| 121 [FLASH] Input format: FASTQ, phred_offset=33 | |
| 122 [FLASH] Output format: FASTQ, phred_offset=33, gzip | |
| 123 [FLASH] | |
| 124 [FLASH] Starting reader and writer threads | |
| 125 [FLASH] Starting 8 combiner threads | |
| 126 [FLASH] Processed 410 read pairs | |
| 127 [FLASH] | |
| 128 [FLASH] Read combination statistics: | |
| 129 [FLASH] Total pairs: 410 | |
| 130 [FLASH] Combined pairs: 387 | |
| 131 [FLASH] Uncombined pairs: 23 | |
| 132 [FLASH] Percent combined: 94.39% | |
| 133 [FLASH] | |
| 134 [FLASH] Writing histogram files. | |
| 135 [FLASH] | |
| 136 [FLASH] FLASH v1.2.11 complete! | |
| 137 [FLASH] 0.022 seconds elapsed | |
| 138 [shovill] Assembling reads with 'spades' | |
| 139 [shovill] Running: spades.py -1 flash.notCombined_1.fastq.gz -2 flash.notCombined_2.fastq.gz --isolate --threads 8 --memory 4 -o spades --tmp-dir /tmp -k 31,51,71,91,111 --merged flash.extendedFrags.fastq.gz 2>&1 | sed 's/^/[spades] /' | tee -a shovill.log | |
| 140 [spades] Command line: /home/piemari/apps/conda/envs/metaphlan/bin/spades.py -1 /home/piemari/shovill_bam/flash.notCombined_1.fastq.gz -2 /home/piemari/shovill_bam/flash.notCombined_2.fastq.gz --isolate --threads 8 --memory 4 -o /home/piemari/shovill_bam/spades --tmp-dir /tmp -k 31,51,71,91,111 --merged /home/piemari/shovill_bam/flash.extendedFrags.fastq.gz | |
| 141 [spades] | |
| 142 [spades] System information: | |
| 143 [spades] SPAdes version: 3.14.1 | |
| 144 [spades] Python version: 3.7.12 | |
| 145 [spades] OS: Linux-3.10.0-1160.62.1.el7.x86_64-x86_64-with-centos-7.9.2009-Core | |
| 146 [spades] | |
| 147 [spades] Output dir: /home/piemari/shovill_bam/spades | |
| 148 [spades] Mode: ONLY assembling (without read error correction) | |
| 149 [spades] Debug mode is turned OFF | |
| 150 [spades] | |
| 151 [spades] Dataset parameters: | |
| 152 [spades] Isolate mode | |
| 153 [spades] Reads: | |
| 154 [spades] Library number: 1, library type: paired-end | |
| 155 [spades] orientation: fr | |
| 156 [spades] left reads: ['/home/piemari/shovill_bam/flash.notCombined_1.fastq.gz'] | |
| 157 [spades] right reads: ['/home/piemari/shovill_bam/flash.notCombined_2.fastq.gz'] | |
| 158 [spades] interlaced reads: not specified | |
| 159 [spades] single reads: not specified | |
| 160 [spades] merged reads: ['/home/piemari/shovill_bam/flash.extendedFrags.fastq.gz'] | |
| 161 [spades] Assembly parameters: | |
| 162 [spades] k: [31, 51, 71, 91, 111] | |
| 163 [spades] Repeat resolution is enabled | |
| 164 [spades] Mismatch careful mode is turned OFF | |
| 165 [spades] MismatchCorrector will be SKIPPED | |
| 166 [spades] Coverage cutoff is turned OFF | |
| 167 [spades] Other parameters: | |
| 168 [spades] Dir for temp files: /tmp | |
| 169 [spades] Threads: 8 | |
| 170 [spades] Memory limit (in Gb): 4 | |
| 171 [spades] | |
| 172 [spades] | |
| 173 [spades] ======= SPAdes pipeline started. Log can be found here: /home/piemari/shovill_bam/spades/spades.log | |
| 174 [spades] | |
| 175 [spades] /home/piemari/shovill_bam/flash.notCombined_1.fastq.gz: max reads length: 150 | |
| 176 [spades] /home/piemari/shovill_bam/flash.notCombined_2.fastq.gz: max reads length: 150 | |
| 177 [spades] Files with merged reads were ignored. | |
| 178 [spades] | |
| 179 [spades] Reads length: 150 | |
| 180 [spades] | |
| 181 [spades] | |
| 182 [spades] ===== Before start started. | |
| 183 [spades] | |
| 184 [spades] | |
| 185 [spades] ===== Assembling started. | |
| 186 [spades] | |
| 187 [spades] | |
| 188 [spades] ===== K31 started. | |
| 189 [spades] | |
| 190 [spades] | |
| 191 [spades] == Running: /home/piemari/apps/conda/envs/metaphlan/bin/spades-core /home/piemari/shovill_bam/spades/K31/configs/config.info /home/piemari/shovill_bam/spades/K31/configs/isolate_mode.info | |
| 192 [spades] | |
| 193 [spades] WARNING: Try to use logger before create one. Level=INFO. Message=Additional contigs is tmp_contigs.fasta | |
| 194 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K31/configs/config.info | |
| 195 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K31/configs/isolate_mode.info | |
| 196 [spades] 0:00:00.000 4M / 10M INFO General (memory_limit.cpp : 49) Memory limit set to 4 Gb | |
| 197 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 85) Starting SPAdes, built from N/A, git revision N/A | |
| 198 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 86) Maximum k-mer length: 128 | |
| 199 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 87) Assembling dataset (/home/piemari/shovill_bam/spades/dataset.info) with K=31 | |
| 200 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 88) Maximum # of threads to use (adjusted due to OMP capabilities): 8 | |
| 201 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 194) SPAdes started | |
| 202 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 201) Starting from stage: read_conversion | |
| 203 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 207) Two-step RR enabled: 0 | |
| 204 [spades] 0:00:00.000 4M / 10M INFO StageManager (stage.cpp : 166) STAGE == Binary Read Conversion | |
| 205 [spades] 0:00:00.002 4M / 12M INFO General (read_converter.cpp : 72) Converting reads to binary format for library #0 (takes a while) | |
| 206 [spades] 0:00:00.002 4M / 12M INFO General (read_converter.cpp : 73) Converting paired reads | |
| 207 [spades] 0:00:00.009 71M / 71M INFO General (binary_converter.cpp : 111) 23 reads written | |
| 208 [spades] 0:00:00.009 47M / 47M INFO General (read_converter.cpp : 81) Converting single reads | |
| 209 [spades] 0:00:00.011 57M / 57M INFO General (binary_converter.cpp : 111) 0 reads written | |
| 210 [spades] 0:00:00.011 57M / 57M INFO General (read_converter.cpp : 87) Converting merged reads | |
| 211 [spades] 0:00:00.017 77M / 77M INFO General (binary_converter.cpp : 111) 387 reads written | |
| 212 [spades] 0:00:00.022 17M / 40M INFO StageManager (stage.cpp : 166) STAGE == de Bruijn graph construction | |
| 213 [spades] 0:00:00.026 17M / 40M INFO General (construction.cpp : 150) Max read length 280 | |
| 214 [spades] 0:00:00.026 17M / 40M INFO General (construction.cpp : 153) Max read length without merged 150 | |
| 215 [spades] 0:00:00.026 17M / 40M INFO General (construction.cpp : 156) Average read length 193.032 | |
| 216 [spades] 0:00:00.026 17M / 40M INFO General (stage.cpp : 113) PROCEDURE == k+1-mer counting | |
| 217 [spades] 0:00:00.026 17M / 40M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. | |
| 218 [spades] 0:00:00.026 17M / 40M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 219 [spades] 0:00:00.027 17M / 40M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166615 Gb | |
| 220 [spades] 0:00:00.027 17M / 40M INFO General (kmer_splitters.hpp : 97) Using cell size of 349417 | |
| 221 [spades] 0:00:00.100 71M / 560M INFO General (kmer_splitters.hpp : 293) Used 866 reads | |
| 222 [spades] 0:00:00.100 71M / 560M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 223 [spades] 0:00:00.111 71M / 560M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 7283 kmers in total. | |
| 224 [spades] 0:00:00.111 71M / 560M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 225 [spades] 0:00:00.114 71M / 560M INFO General (stage.cpp : 113) PROCEDURE == Extension index construction | |
| 226 [spades] 0:00:00.114 71M / 560M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 227 [spades] 0:00:00.114 71M / 560M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 228 [spades] 0:00:00.115 71M / 560M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 229 [spades] 0:00:00.115 71M / 560M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166468 Gb | |
| 230 [spades] 0:00:00.115 71M / 560M INFO General (kmer_splitters.hpp : 97) Using cell size of 174554 | |
| 231 [spades] 0:00:00.188 2G / 2G INFO General (kmer_splitters.hpp : 364) Processed 7283 kmers | |
| 232 [spades] 0:00:00.188 2G / 2G INFO General (kmer_splitters.hpp : 369) Used 7283 kmers. | |
| 233 [spades] 0:00:00.212 85M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 234 [spades] 0:00:00.236 85M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 7222 kmers in total. | |
| 235 [spades] 0:00:00.236 85M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 236 [spades] 0:00:00.241 85M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 237 [spades] 0:00:00.264 86M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 238 [spades] 0:00:00.266 86M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12384 bytes occupied (13.7181 bits per kmer). | |
| 239 [spades] 0:00:00.266 86M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers | |
| 240 [spades] 0:00:00.273 86M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. | |
| 241 [spades] 0:00:00.274 86M / 2G INFO General (stage.cpp : 113) PROCEDURE == Early tip clipping | |
| 242 [spades] 0:00:00.274 86M / 2G INFO General (construction.cpp : 293) Early tip clipper length bound set as (RL - K) | |
| 243 [spades] 0:00:00.274 86M / 2G INFO Early tip clipping (early_simplification.hpp : 28) Early tip clipping | |
| 244 [spades] 0:00:00.279 86M / 2G INFO Early tip clipping (early_simplification.hpp : 63) #tipped junctions: 96 | |
| 245 [spades] 0:00:00.284 86M / 2G INFO Early tip clipping (early_simplification.hpp : 74) Clipped tips: 97 | |
| 246 [spades] 0:00:00.284 86M / 2G INFO Early tip clipping (early_simplification.hpp : 30) 2642 32-mers were removed by early tip clipper | |
| 247 [spades] 0:00:00.285 86M / 2G INFO General (stage.cpp : 113) PROCEDURE == Condensing graph | |
| 248 [spades] 0:00:00.285 86M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths | |
| 249 [spades] 0:00:00.287 86M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 186 sequences extracted | |
| 250 [spades] 0:00:00.288 86M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops | |
| 251 [spades] 0:00:00.289 86M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 0 loops collected | |
| 252 [spades] 0:00:00.290 86M / 2G INFO General (stage.cpp : 113) PROCEDURE == Filling coverage indices (PHM) | |
| 253 [spades] 0:00:00.290 86M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 254 [spades] 0:00:00.290 86M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 255 [spades] 0:00:00.301 87M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 7864 bytes occupied (8.6382 bits per kmer). | |
| 256 [spades] 0:00:00.301 87M / 2G INFO General (construction.cpp : 429) Collecting k-mer coverage information from reads, this takes a while. | |
| 257 [spades] 0:00:00.310 87M / 2G INFO General (construction.cpp : 549) Filling coverage and flanking coverage from PHM | |
| 258 [spades] 0:00:00.314 87M / 2G INFO StageManager (stage.cpp : 166) STAGE == EC Threshold Finding | |
| 259 [spades] 0:00:00.314 87M / 2G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 | |
| 260 [spades] 0:00:00.315 87M / 2G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 60 | |
| 261 [spades] 0:00:00.315 87M / 2G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 60. Coverage mad: 7.413 | |
| 262 [spades] 0:00:00.315 87M / 2G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model | |
| 263 [spades] 0:00:00.324 87M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 | |
| 264 [spades] 0:00:00.349 87M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 | |
| 265 [spades] 0:00:00.414 87M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 | |
| 266 [spades] 0:00:00.501 87M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 | |
| 267 [spades] 0:00:00.540 87M / 2G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 56.9644. Fitted coverage std. dev: 9.10691 | |
| 268 [spades] 0:00:00.540 87M / 2G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 1 | |
| 269 [spades] 0:00:00.541 87M / 2G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 39 | |
| 270 [spades] 0:00:00.541 87M / 2G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 29 | |
| 271 [spades] 0:00:00.541 87M / 2G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 1104 | |
| 272 [spades] 0:00:00.541 87M / 2G INFO General (genomic_info_filler.cpp : 53) Mean coverage was calculated as 56.9644 | |
| 273 [spades] 0:00:00.541 87M / 2G INFO General (genomic_info_filler.cpp : 68) EC coverage threshold value was calculated as 29 | |
| 274 [spades] 0:00:00.542 87M / 2G INFO General (genomic_info_filler.cpp : 69) Trusted kmer low bound: 0 | |
| 275 [spades] 0:00:00.542 87M / 2G INFO StageManager (stage.cpp : 166) STAGE == Raw Simplification | |
| 276 [spades] 0:00:00.542 87M / 2G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning | |
| 277 [spades] 0:00:00.542 87M / 2G INFO General (graph_simplification.hpp : 671) Flanking coverage based disconnection disabled | |
| 278 [spades] 0:00:00.542 87M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover | |
| 279 [spades] 0:00:00.545 87M / 2G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times | |
| 280 [spades] 0:00:00.545 87M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification | |
| 281 [spades] 0:00:00.546 87M / 2G INFO General (simplification.cpp : 383) Graph simplification started | |
| 282 [spades] 0:00:00.546 87M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 283 [spades] 0:00:00.546 87M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 1 | |
| 284 [spades] 0:00:00.546 87M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 285 [spades] 0:00:00.550 87M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 286 [spades] 0:00:00.550 87M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 287 [spades] 0:00:00.557 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 60 times | |
| 288 [spades] 0:00:00.557 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 289 [spades] 0:00:00.559 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3 times | |
| 290 [spades] 0:00:00.560 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 2 | |
| 291 [spades] 0:00:00.560 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 292 [spades] 0:00:00.560 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 293 [spades] 0:00:00.561 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 294 [spades] 0:00:00.561 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 295 [spades] 0:00:00.561 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 296 [spades] 0:00:00.561 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 297 [spades] 0:00:00.562 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 3 | |
| 298 [spades] 0:00:00.562 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 299 [spades] 0:00:00.562 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 300 [spades] 0:00:00.562 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 301 [spades] 0:00:00.562 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 302 [spades] 0:00:00.563 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 303 [spades] 0:00:00.563 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 304 [spades] 0:00:00.563 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 4 | |
| 305 [spades] 0:00:00.563 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 306 [spades] 0:00:00.563 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 307 [spades] 0:00:00.564 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 308 [spades] 0:00:00.564 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 309 [spades] 0:00:00.564 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 310 [spades] 0:00:00.564 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 311 [spades] 0:00:00.564 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 5 | |
| 312 [spades] 0:00:00.564 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 313 [spades] 0:00:00.565 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 314 [spades] 0:00:00.565 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 315 [spades] 0:00:00.565 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 316 [spades] 0:00:00.565 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 317 [spades] 0:00:00.565 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 318 [spades] 0:00:00.566 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 6 | |
| 319 [spades] 0:00:00.566 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 320 [spades] 0:00:00.566 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 321 [spades] 0:00:00.566 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 322 [spades] 0:00:00.566 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 323 [spades] 0:00:00.567 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 324 [spades] 0:00:00.567 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 325 [spades] 0:00:00.567 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 7 | |
| 326 [spades] 0:00:00.567 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 327 [spades] 0:00:00.567 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 328 [spades] 0:00:00.568 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 329 [spades] 0:00:00.568 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 330 [spades] 0:00:00.568 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 331 [spades] 0:00:00.568 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 332 [spades] 0:00:00.568 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 8 | |
| 333 [spades] 0:00:00.568 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 334 [spades] 0:00:00.569 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 335 [spades] 0:00:00.569 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 336 [spades] 0:00:00.569 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 337 [spades] 0:00:00.569 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 338 [spades] 0:00:00.569 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 339 [spades] 0:00:00.570 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 9 | |
| 340 [spades] 0:00:00.570 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 341 [spades] 0:00:00.570 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 342 [spades] 0:00:00.570 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 343 [spades] 0:00:00.570 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 344 [spades] 0:00:00.571 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 345 [spades] 0:00:00.571 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 346 [spades] 0:00:00.571 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 10 | |
| 347 [spades] 0:00:00.571 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 348 [spades] 0:00:00.571 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 349 [spades] 0:00:00.571 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 350 [spades] 0:00:00.572 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 351 [spades] 0:00:00.572 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 352 [spades] 0:00:00.572 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 353 [spades] 0:00:00.572 84M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 11 | |
| 354 [spades] 0:00:00.572 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 355 [spades] 0:00:00.575 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 356 [spades] 0:00:00.575 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 357 [spades] 0:00:00.576 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 358 [spades] 0:00:00.576 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 359 [spades] 0:00:00.576 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 360 [spades] 0:00:00.576 84M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification Cleanup | |
| 361 [spades] 0:00:00.576 84M / 2G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification | |
| 362 [spades] 0:00:00.577 84M / 2G INFO General (graph_simplification.hpp : 456) Disconnection of relatively low covered edges disabled | |
| 363 [spades] 0:00:00.577 84M / 2G INFO General (graph_simplification.hpp : 493) Complex tip clipping disabled | |
| 364 [spades] 0:00:00.577 84M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 365 [spades] 0:00:00.577 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 366 [spades] 0:00:00.578 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 367 [spades] 0:00:00.578 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 368 [spades] 0:00:00.578 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 369 [spades] 0:00:00.578 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 370 [spades] 0:00:00.579 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 371 [spades] 0:00:00.579 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 372 [spades] 0:00:00.579 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 373 [spades] 0:00:00.579 84M / 2G INFO General (simplification.cpp : 343) Disrupting self-conjugate edges | |
| 374 [spades] 0:00:00.579 84M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges | |
| 375 [spades] 0:00:00.580 84M / 2G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 1 times | |
| 376 [spades] 0:00:00.580 84M / 2G INFO General (simplification.cpp : 496) Counting average coverage | |
| 377 [spades] 0:00:00.580 84M / 2G INFO General (simplification.cpp : 502) Average coverage = 55.1872 | |
| 378 [spades] 0:00:00.580 84M / 2G INFO StageManager (stage.cpp : 166) STAGE == Contig Output | |
| 379 [spades] 0:00:00.583 84M / 2G INFO General (read_converter.cpp : 102) Outputting contigs to /home/piemari/shovill_bam/spades/K31/simplified_contigs | |
| 380 [spades] 0:00:00.585 84M / 2G INFO General (binary_converter.cpp : 111) 1 reads written | |
| 381 [spades] 0:00:00.589 84M / 2G INFO General (pipeline.cpp : 259) SPAdes finished | |
| 382 [spades] 0:00:00.590 84M / 2G INFO General (main.cpp : 107) Assembling time: 0 hours 0 minutes 0 seconds | |
| 383 [spades] | |
| 384 [spades] ===== K31 finished. | |
| 385 [spades] | |
| 386 [spades] | |
| 387 [spades] ===== K51 started. | |
| 388 [spades] | |
| 389 [spades] | |
| 390 [spades] == Running: /home/piemari/apps/conda/envs/metaphlan/bin/spades-core /home/piemari/shovill_bam/spades/K51/configs/config.info /home/piemari/shovill_bam/spades/K51/configs/isolate_mode.info | |
| 391 [spades] | |
| 392 [spades] WARNING: Try to use logger before create one. Level=INFO. Message=Additional contigs is /home/piemari/shovill_bam/spades/K31/simplified_contigs | |
| 393 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K51/configs/config.info | |
| 394 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K51/configs/isolate_mode.info | |
| 395 [spades] 0:00:00.000 4M / 10M INFO General (memory_limit.cpp : 49) Memory limit set to 4 Gb | |
| 396 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 85) Starting SPAdes, built from N/A, git revision N/A | |
| 397 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 86) Maximum k-mer length: 128 | |
| 398 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 87) Assembling dataset (/home/piemari/shovill_bam/spades/dataset.info) with K=51 | |
| 399 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 88) Maximum # of threads to use (adjusted due to OMP capabilities): 8 | |
| 400 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 194) SPAdes started | |
| 401 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 201) Starting from stage: read_conversion | |
| 402 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 207) Two-step RR enabled: 0 | |
| 403 [spades] 0:00:00.000 4M / 10M INFO StageManager (stage.cpp : 166) STAGE == Binary Read Conversion | |
| 404 [spades] 0:00:00.001 4M / 12M INFO General (read_converter.cpp : 53) Binary reads detected | |
| 405 [spades] 0:00:00.002 4M / 14M INFO StageManager (stage.cpp : 166) STAGE == de Bruijn graph construction | |
| 406 [spades] 0:00:00.002 4M / 14M INFO General (construction.cpp : 115) Contigs from previous K will be used: /home/piemari/shovill_bam/spades/K31/simplified_contigs | |
| 407 [spades] 0:00:00.007 4M / 14M INFO General (construction.cpp : 150) Max read length 280 | |
| 408 [spades] 0:00:00.007 4M / 14M INFO General (construction.cpp : 153) Max read length without merged 150 | |
| 409 [spades] 0:00:00.007 4M / 14M INFO General (construction.cpp : 156) Average read length 193.032 | |
| 410 [spades] 0:00:00.007 4M / 14M INFO General (stage.cpp : 113) PROCEDURE == k+1-mer counting | |
| 411 [spades] 0:00:00.007 4M / 14M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. | |
| 412 [spades] 0:00:00.007 4M / 14M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 413 [spades] 0:00:00.007 4M / 14M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166632 Gb | |
| 414 [spades] 0:00:00.007 4M / 14M INFO General (kmer_splitters.hpp : 97) Using cell size of 174726 | |
| 415 [spades] 0:00:00.085 84M / 556M INFO General (kmer_splitters.hpp : 293) Used 868 reads | |
| 416 [spades] 0:00:00.085 84M / 556M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 417 [spades] 0:00:00.102 84M / 556M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8238 kmers in total. | |
| 418 [spades] 0:00:00.102 84M / 556M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 419 [spades] 0:00:00.106 84M / 556M INFO General (stage.cpp : 113) PROCEDURE == Extension index construction | |
| 420 [spades] 0:00:00.106 84M / 556M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 421 [spades] 0:00:00.106 84M / 556M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 422 [spades] 0:00:00.106 84M / 556M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 423 [spades] 0:00:00.106 84M / 556M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166509 Gb | |
| 424 [spades] 0:00:00.107 84M / 556M INFO General (kmer_splitters.hpp : 97) Using cell size of 87298 | |
| 425 [spades] 0:00:00.181 2G / 2G INFO General (kmer_splitters.hpp : 364) Processed 8238 kmers | |
| 426 [spades] 0:00:00.181 2G / 2G INFO General (kmer_splitters.hpp : 369) Used 8238 kmers. | |
| 427 [spades] 0:00:00.203 97M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 428 [spades] 0:00:00.220 97M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8201 kmers in total. | |
| 429 [spades] 0:00:00.221 97M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 430 [spades] 0:00:00.226 97M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 431 [spades] 0:00:00.252 92M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 432 [spades] 0:00:00.253 92M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12872 bytes occupied (12.5565 bits per kmer). | |
| 433 [spades] 0:00:00.254 92M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers | |
| 434 [spades] 0:00:00.257 92M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. | |
| 435 [spades] 0:00:00.258 92M / 2G INFO General (stage.cpp : 113) PROCEDURE == Early tip clipping | |
| 436 [spades] 0:00:00.258 92M / 2G INFO General (construction.cpp : 293) Early tip clipper length bound set as (RL - K) | |
| 437 [spades] 0:00:00.259 92M / 2G INFO Early tip clipping (early_simplification.hpp : 28) Early tip clipping | |
| 438 [spades] 0:00:00.263 92M / 2G INFO Early tip clipping (early_simplification.hpp : 63) #tipped junctions: 115 | |
| 439 [spades] 0:00:00.268 92M / 2G INFO Early tip clipping (early_simplification.hpp : 74) Clipped tips: 116 | |
| 440 [spades] 0:00:00.268 92M / 2G INFO Early tip clipping (early_simplification.hpp : 30) 3952 52-mers were removed by early tip clipper | |
| 441 [spades] 0:00:00.268 92M / 2G INFO General (stage.cpp : 113) PROCEDURE == Condensing graph | |
| 442 [spades] 0:00:00.269 92M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths | |
| 443 [spades] 0:00:00.272 92M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 118 sequences extracted | |
| 444 [spades] 0:00:00.273 92M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops | |
| 445 [spades] 0:00:00.274 92M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 0 loops collected | |
| 446 [spades] 0:00:00.274 92M / 2G INFO General (stage.cpp : 113) PROCEDURE == Filling coverage indices (PHM) | |
| 447 [spades] 0:00:00.275 92M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 448 [spades] 0:00:00.275 92M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 449 [spades] 0:00:00.286 92M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 8280 bytes occupied (8.04079 bits per kmer). | |
| 450 [spades] 0:00:00.286 92M / 2G INFO General (construction.cpp : 429) Collecting k-mer coverage information from reads, this takes a while. | |
| 451 [spades] 0:00:00.294 92M / 2G INFO General (construction.cpp : 549) Filling coverage and flanking coverage from PHM | |
| 452 [spades] 0:00:00.297 92M / 2G INFO StageManager (stage.cpp : 166) STAGE == EC Threshold Finding | |
| 453 [spades] 0:00:00.297 92M / 2G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 | |
| 454 [spades] 0:00:00.297 92M / 2G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 51 | |
| 455 [spades] 0:00:00.298 92M / 2G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 51. Coverage mad: 7.413 | |
| 456 [spades] 0:00:00.298 92M / 2G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model | |
| 457 [spades] 0:00:00.306 92M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 | |
| 458 [spades] 0:00:00.326 92M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 | |
| 459 [spades] 0:00:00.371 92M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 | |
| 460 [spades] 0:00:00.392 92M / 2G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 48.7323. Fitted coverage std. dev: 7.8967 | |
| 461 [spades] 0:00:00.392 92M / 2G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 1 | |
| 462 [spades] 0:00:00.393 92M / 2G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 33 | |
| 463 [spades] 0:00:00.393 92M / 2G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 25 | |
| 464 [spades] 0:00:00.393 92M / 2G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 1099 | |
| 465 [spades] 0:00:00.393 92M / 2G INFO General (genomic_info_filler.cpp : 53) Mean coverage was calculated as 48.7323 | |
| 466 [spades] 0:00:00.393 92M / 2G INFO General (genomic_info_filler.cpp : 68) EC coverage threshold value was calculated as 25 | |
| 467 [spades] 0:00:00.394 92M / 2G INFO General (genomic_info_filler.cpp : 69) Trusted kmer low bound: 0 | |
| 468 [spades] 0:00:00.394 92M / 2G INFO StageManager (stage.cpp : 166) STAGE == Raw Simplification | |
| 469 [spades] 0:00:00.394 92M / 2G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning | |
| 470 [spades] 0:00:00.394 92M / 2G INFO General (graph_simplification.hpp : 671) Flanking coverage based disconnection disabled | |
| 471 [spades] 0:00:00.394 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover | |
| 472 [spades] 0:00:00.397 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times | |
| 473 [spades] 0:00:00.397 92M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification | |
| 474 [spades] 0:00:00.398 92M / 2G INFO General (simplification.cpp : 383) Graph simplification started | |
| 475 [spades] 0:00:00.398 92M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 476 [spades] 0:00:00.398 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 1 | |
| 477 [spades] 0:00:00.399 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 478 [spades] 0:00:00.399 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 479 [spades] 0:00:00.399 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 480 [spades] 0:00:00.401 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 40 times | |
| 481 [spades] 0:00:00.402 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 482 [spades] 0:00:00.402 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 483 [spades] 0:00:00.402 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 2 | |
| 484 [spades] 0:00:00.403 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 485 [spades] 0:00:00.403 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 486 [spades] 0:00:00.403 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 487 [spades] 0:00:00.404 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 488 [spades] 0:00:00.404 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 489 [spades] 0:00:00.404 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 490 [spades] 0:00:00.405 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 3 | |
| 491 [spades] 0:00:00.405 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 492 [spades] 0:00:00.405 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 493 [spades] 0:00:00.405 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 494 [spades] 0:00:00.405 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 495 [spades] 0:00:00.405 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 496 [spades] 0:00:00.406 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 497 [spades] 0:00:00.406 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 4 | |
| 498 [spades] 0:00:00.406 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 499 [spades] 0:00:00.406 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 500 [spades] 0:00:00.406 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 501 [spades] 0:00:00.406 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 502 [spades] 0:00:00.407 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 503 [spades] 0:00:00.407 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 504 [spades] 0:00:00.407 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 5 | |
| 505 [spades] 0:00:00.407 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 506 [spades] 0:00:00.407 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 507 [spades] 0:00:00.407 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 508 [spades] 0:00:00.408 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 509 [spades] 0:00:00.408 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 510 [spades] 0:00:00.408 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 511 [spades] 0:00:00.408 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 6 | |
| 512 [spades] 0:00:00.408 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 513 [spades] 0:00:00.408 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 514 [spades] 0:00:00.408 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 515 [spades] 0:00:00.409 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 516 [spades] 0:00:00.409 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 517 [spades] 0:00:00.409 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 518 [spades] 0:00:00.409 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 7 | |
| 519 [spades] 0:00:00.409 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 520 [spades] 0:00:00.409 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 521 [spades] 0:00:00.410 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 522 [spades] 0:00:00.410 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 523 [spades] 0:00:00.410 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 524 [spades] 0:00:00.410 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 525 [spades] 0:00:00.410 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 8 | |
| 526 [spades] 0:00:00.410 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 527 [spades] 0:00:00.411 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 528 [spades] 0:00:00.411 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 529 [spades] 0:00:00.411 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 530 [spades] 0:00:00.411 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 531 [spades] 0:00:00.411 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 532 [spades] 0:00:00.411 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 9 | |
| 533 [spades] 0:00:00.412 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 534 [spades] 0:00:00.412 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 535 [spades] 0:00:00.412 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 536 [spades] 0:00:00.412 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 537 [spades] 0:00:00.412 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 538 [spades] 0:00:00.412 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 539 [spades] 0:00:00.413 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 10 | |
| 540 [spades] 0:00:00.413 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 541 [spades] 0:00:00.413 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 542 [spades] 0:00:00.413 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 543 [spades] 0:00:00.413 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 544 [spades] 0:00:00.413 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 545 [spades] 0:00:00.413 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 546 [spades] 0:00:00.414 92M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 11 | |
| 547 [spades] 0:00:00.414 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 548 [spades] 0:00:00.416 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 549 [spades] 0:00:00.416 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 550 [spades] 0:00:00.416 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 551 [spades] 0:00:00.417 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 552 [spades] 0:00:00.417 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 553 [spades] 0:00:00.417 92M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification Cleanup | |
| 554 [spades] 0:00:00.418 92M / 2G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification | |
| 555 [spades] 0:00:00.418 92M / 2G INFO General (graph_simplification.hpp : 456) Disconnection of relatively low covered edges disabled | |
| 556 [spades] 0:00:00.418 92M / 2G INFO General (graph_simplification.hpp : 493) Complex tip clipping disabled | |
| 557 [spades] 0:00:00.419 92M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 558 [spades] 0:00:00.419 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 559 [spades] 0:00:00.419 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 560 [spades] 0:00:00.420 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 561 [spades] 0:00:00.420 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 562 [spades] 0:00:00.420 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 563 [spades] 0:00:00.421 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 564 [spades] 0:00:00.421 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 565 [spades] 0:00:00.421 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 566 [spades] 0:00:00.421 92M / 2G INFO General (simplification.cpp : 343) Disrupting self-conjugate edges | |
| 567 [spades] 0:00:00.422 92M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges | |
| 568 [spades] 0:00:00.422 92M / 2G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 2 times | |
| 569 [spades] 0:00:00.422 92M / 2G INFO General (simplification.cpp : 496) Counting average coverage | |
| 570 [spades] 0:00:00.423 92M / 2G INFO General (simplification.cpp : 502) Average coverage = 47.8689 | |
| 571 [spades] 0:00:00.423 92M / 2G INFO StageManager (stage.cpp : 166) STAGE == Contig Output | |
| 572 [spades] 0:00:00.424 92M / 2G INFO General (read_converter.cpp : 102) Outputting contigs to /home/piemari/shovill_bam/spades/K51/simplified_contigs | |
| 573 [spades] 0:00:00.426 92M / 2G INFO General (binary_converter.cpp : 111) 1 reads written | |
| 574 [spades] 0:00:00.433 92M / 2G INFO General (pipeline.cpp : 259) SPAdes finished | |
| 575 [spades] 0:00:00.433 92M / 2G INFO General (main.cpp : 107) Assembling time: 0 hours 0 minutes 0 seconds | |
| 576 [spades] | |
| 577 [spades] ===== K51 finished. | |
| 578 [spades] | |
| 579 [spades] | |
| 580 [spades] ===== K71 started. | |
| 581 [spades] | |
| 582 [spades] | |
| 583 [spades] == Running: /home/piemari/apps/conda/envs/metaphlan/bin/spades-core /home/piemari/shovill_bam/spades/K71/configs/config.info /home/piemari/shovill_bam/spades/K71/configs/isolate_mode.info | |
| 584 [spades] | |
| 585 [spades] WARNING: Try to use logger before create one. Level=INFO. Message=Additional contigs is /home/piemari/shovill_bam/spades/K51/simplified_contigs | |
| 586 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K71/configs/config.info | |
| 587 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K71/configs/isolate_mode.info | |
| 588 [spades] 0:00:00.000 4M / 10M INFO General (memory_limit.cpp : 49) Memory limit set to 4 Gb | |
| 589 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 85) Starting SPAdes, built from N/A, git revision N/A | |
| 590 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 86) Maximum k-mer length: 128 | |
| 591 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 87) Assembling dataset (/home/piemari/shovill_bam/spades/dataset.info) with K=71 | |
| 592 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 88) Maximum # of threads to use (adjusted due to OMP capabilities): 8 | |
| 593 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 194) SPAdes started | |
| 594 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 201) Starting from stage: read_conversion | |
| 595 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 207) Two-step RR enabled: 0 | |
| 596 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 218) Will need read mapping, kmer mapper will be attached | |
| 597 [spades] 0:00:00.000 4M / 10M INFO StageManager (stage.cpp : 166) STAGE == Binary Read Conversion | |
| 598 [spades] 0:00:00.001 4M / 12M INFO General (read_converter.cpp : 53) Binary reads detected | |
| 599 [spades] 0:00:00.001 4M / 14M INFO StageManager (stage.cpp : 166) STAGE == de Bruijn graph construction | |
| 600 [spades] 0:00:00.001 4M / 14M INFO General (construction.cpp : 115) Contigs from previous K will be used: /home/piemari/shovill_bam/spades/K51/simplified_contigs | |
| 601 [spades] 0:00:00.006 4M / 14M INFO General (construction.cpp : 150) Max read length 280 | |
| 602 [spades] 0:00:00.006 4M / 14M INFO General (construction.cpp : 153) Max read length without merged 150 | |
| 603 [spades] 0:00:00.006 4M / 14M INFO General (construction.cpp : 156) Average read length 193.032 | |
| 604 [spades] 0:00:00.006 4M / 14M INFO General (stage.cpp : 113) PROCEDURE == k+1-mer counting | |
| 605 [spades] 0:00:00.006 4M / 14M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. | |
| 606 [spades] 0:00:00.007 4M / 14M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 607 [spades] 0:00:00.007 4M / 14M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166632 Gb | |
| 608 [spades] 0:00:00.007 4M / 14M INFO General (kmer_splitters.hpp : 97) Using cell size of 116484 | |
| 609 [spades] 0:00:00.088 81M / 554M INFO General (kmer_splitters.hpp : 293) Used 868 reads | |
| 610 [spades] 0:00:00.088 81M / 554M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 611 [spades] 0:00:00.100 83M / 554M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8725 kmers in total. | |
| 612 [spades] 0:00:00.100 83M / 554M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 613 [spades] 0:00:00.104 83M / 554M INFO General (stage.cpp : 113) PROCEDURE == Extension index construction | |
| 614 [spades] 0:00:00.104 83M / 554M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 615 [spades] 0:00:00.104 83M / 554M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 616 [spades] 0:00:00.104 83M / 554M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 617 [spades] 0:00:00.104 83M / 554M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166542 Gb | |
| 618 [spades] 0:00:00.104 83M / 554M INFO General (kmer_splitters.hpp : 97) Using cell size of 58210 | |
| 619 [spades] 0:00:00.177 2G / 2G INFO General (kmer_splitters.hpp : 364) Processed 8725 kmers | |
| 620 [spades] 0:00:00.177 2G / 2G INFO General (kmer_splitters.hpp : 369) Used 8725 kmers. | |
| 621 [spades] 0:00:00.200 89M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 622 [spades] 0:00:00.218 89M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8713 kmers in total. | |
| 623 [spades] 0:00:00.218 89M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 624 [spades] 0:00:00.224 89M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 625 [spades] 0:00:00.249 87M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 626 [spades] 0:00:00.251 87M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13120 bytes occupied (12.0464 bits per kmer). | |
| 627 [spades] 0:00:00.251 87M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers | |
| 628 [spades] 0:00:00.254 87M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. | |
| 629 [spades] 0:00:00.255 87M / 2G INFO General (stage.cpp : 113) PROCEDURE == Condensing graph | |
| 630 [spades] 0:00:00.255 87M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths | |
| 631 [spades] 0:00:00.260 87M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 308 sequences extracted | |
| 632 [spades] 0:00:00.266 87M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops | |
| 633 [spades] 0:00:00.271 87M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 0 loops collected | |
| 634 [spades] 0:00:00.280 87M / 2G INFO General (stage.cpp : 113) PROCEDURE == Filling coverage indices (PHM) | |
| 635 [spades] 0:00:00.281 87M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 636 [spades] 0:00:00.281 87M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 637 [spades] 0:00:00.294 87M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 8536 bytes occupied (7.8267 bits per kmer). | |
| 638 [spades] 0:00:00.294 87M / 2G INFO General (construction.cpp : 429) Collecting k-mer coverage information from reads, this takes a while. | |
| 639 [spades] 0:00:00.300 87M / 2G INFO General (construction.cpp : 549) Filling coverage and flanking coverage from PHM | |
| 640 [spades] 0:00:00.307 87M / 2G INFO StageManager (stage.cpp : 166) STAGE == EC Threshold Finding | |
| 641 [spades] 0:00:00.308 87M / 2G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 | |
| 642 [spades] 0:00:00.308 87M / 2G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 44 | |
| 643 [spades] 0:00:00.308 87M / 2G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 44. Coverage mad: 7.413 | |
| 644 [spades] 0:00:00.308 87M / 2G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model | |
| 645 [spades] 0:00:00.315 87M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 | |
| 646 [spades] 0:00:00.334 87M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 | |
| 647 [spades] 0:00:00.377 87M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 | |
| 648 [spades] 0:00:00.421 87M / 2G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 40.9755. Fitted coverage std. dev: 6.3525 | |
| 649 [spades] 0:00:00.421 87M / 2G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 1 | |
| 650 [spades] 0:00:00.421 87M / 2G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 28 | |
| 651 [spades] 0:00:00.421 87M / 2G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 21 | |
| 652 [spades] 0:00:00.422 87M / 2G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 1088 | |
| 653 [spades] 0:00:00.422 87M / 2G INFO General (genomic_info_filler.cpp : 53) Mean coverage was calculated as 40.9755 | |
| 654 [spades] 0:00:00.422 87M / 2G INFO General (genomic_info_filler.cpp : 68) EC coverage threshold value was calculated as 21 | |
| 655 [spades] 0:00:00.422 87M / 2G INFO General (genomic_info_filler.cpp : 69) Trusted kmer low bound: 0 | |
| 656 [spades] 0:00:00.423 87M / 2G INFO StageManager (stage.cpp : 166) STAGE == Gap Closer | |
| 657 [spades] 0:00:00.423 87M / 2G INFO General (graph_pack.hpp : 105) Index refill | |
| 658 [spades] 0:00:00.423 87M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 659 [spades] 0:00:00.423 87M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 660 [spades] 0:00:00.424 87M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 661 [spades] 0:00:00.424 87M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166486 Gb | |
| 662 [spades] 0:00:00.424 87M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 58191 | |
| 663 [spades] 0:00:00.513 2G / 2G INFO General (edge_index_builders.hpp : 82) Used 616 sequences. | |
| 664 [spades] 0:00:00.531 94M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 665 [spades] 0:00:00.562 94M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8725 kmers in total. | |
| 666 [spades] 0:00:00.563 94M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 667 [spades] 0:00:00.568 94M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 668 [spades] 0:00:00.586 89M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 669 [spades] 0:00:00.588 89M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13104 bytes occupied (12.0151 bits per kmer). | |
| 670 [spades] 0:00:00.588 89M / 2G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. | |
| 671 [spades] 0:00:00.592 89M / 2G INFO General (edge_index.hpp : 92) Index refilled | |
| 672 [spades] 0:00:00.595 89M / 2G INFO General (gap_closer.cpp : 147) Preparing shift maps | |
| 673 [spades] 0:00:00.596 89M / 2G INFO General (gap_closer.cpp : 107) Processing paired reads (takes a while) | |
| 674 [spades] 0:00:00.598 89M / 2G INFO General (gap_closer.cpp : 126) Used 23 paired reads | |
| 675 [spades] 0:00:00.598 89M / 2G INFO General (gap_closer.cpp : 128) Merging paired indices | |
| 676 [spades] 0:00:00.598 89M / 2G INFO GapCloser (gap_closer.cpp : 332) Closing short gaps | |
| 677 [spades] 0:00:00.599 89M / 2G INFO GapCloser (gap_closer.cpp : 364) Closing short gaps complete: filled 0 gaps after checking 0 candidates | |
| 678 [spades] 0:00:00.599 89M / 2G INFO StageManager (stage.cpp : 166) STAGE == Raw Simplification | |
| 679 [spades] 0:00:00.599 89M / 2G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning | |
| 680 [spades] 0:00:00.600 89M / 2G INFO General (graph_simplification.hpp : 671) Flanking coverage based disconnection disabled | |
| 681 [spades] 0:00:00.600 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover | |
| 682 [spades] 0:00:00.600 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times | |
| 683 [spades] 0:00:00.600 89M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification | |
| 684 [spades] 0:00:00.601 89M / 2G INFO General (simplification.cpp : 383) Graph simplification started | |
| 685 [spades] 0:00:00.601 89M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 686 [spades] 0:00:00.601 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 1 | |
| 687 [spades] 0:00:00.601 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 688 [spades] 0:00:00.603 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 128 times | |
| 689 [spades] 0:00:00.603 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 690 [spades] 0:00:00.607 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 19 times | |
| 691 [spades] 0:00:00.607 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 692 [spades] 0:00:00.609 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 693 [spades] 0:00:00.609 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 2 | |
| 694 [spades] 0:00:00.609 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 695 [spades] 0:00:00.610 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 696 [spades] 0:00:00.610 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 697 [spades] 0:00:00.610 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 698 [spades] 0:00:00.610 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 699 [spades] 0:00:00.611 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 700 [spades] 0:00:00.611 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 3 | |
| 701 [spades] 0:00:00.611 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 702 [spades] 0:00:00.611 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 703 [spades] 0:00:00.611 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 704 [spades] 0:00:00.612 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 705 [spades] 0:00:00.612 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 706 [spades] 0:00:00.612 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 707 [spades] 0:00:00.612 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 4 | |
| 708 [spades] 0:00:00.612 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 709 [spades] 0:00:00.612 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 710 [spades] 0:00:00.613 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 711 [spades] 0:00:00.613 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 712 [spades] 0:00:00.613 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 713 [spades] 0:00:00.613 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 714 [spades] 0:00:00.613 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 5 | |
| 715 [spades] 0:00:00.613 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 716 [spades] 0:00:00.614 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 717 [spades] 0:00:00.614 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 718 [spades] 0:00:00.614 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 719 [spades] 0:00:00.614 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 720 [spades] 0:00:00.614 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 721 [spades] 0:00:00.614 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 6 | |
| 722 [spades] 0:00:00.615 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 723 [spades] 0:00:00.615 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 724 [spades] 0:00:00.615 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 725 [spades] 0:00:00.615 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 726 [spades] 0:00:00.615 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 727 [spades] 0:00:00.615 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 728 [spades] 0:00:00.616 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 7 | |
| 729 [spades] 0:00:00.616 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 730 [spades] 0:00:00.616 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 731 [spades] 0:00:00.616 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 732 [spades] 0:00:00.616 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 733 [spades] 0:00:00.617 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 734 [spades] 0:00:00.617 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 735 [spades] 0:00:00.617 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 8 | |
| 736 [spades] 0:00:00.617 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 737 [spades] 0:00:00.617 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 738 [spades] 0:00:00.617 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 739 [spades] 0:00:00.618 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 740 [spades] 0:00:00.618 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 741 [spades] 0:00:00.618 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 742 [spades] 0:00:00.618 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 9 | |
| 743 [spades] 0:00:00.618 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 744 [spades] 0:00:00.618 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 745 [spades] 0:00:00.619 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 746 [spades] 0:00:00.619 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 747 [spades] 0:00:00.619 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 748 [spades] 0:00:00.619 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 749 [spades] 0:00:00.619 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 10 | |
| 750 [spades] 0:00:00.619 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 751 [spades] 0:00:00.620 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 752 [spades] 0:00:00.620 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 753 [spades] 0:00:00.620 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 754 [spades] 0:00:00.620 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 755 [spades] 0:00:00.620 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 756 [spades] 0:00:00.620 89M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 11 | |
| 757 [spades] 0:00:00.621 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 758 [spades] 0:00:00.623 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 759 [spades] 0:00:00.623 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 760 [spades] 0:00:00.623 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 761 [spades] 0:00:00.623 89M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 762 [spades] 0:00:00.624 89M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 763 [spades] 0:00:00.624 89M / 2G INFO StageManager (stage.cpp : 166) STAGE == Gap Closer | |
| 764 [spades] 0:00:00.624 89M / 2G INFO General (graph_pack.hpp : 105) Index refill | |
| 765 [spades] 0:00:00.625 89M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 766 [spades] 0:00:00.625 89M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 767 [spades] 0:00:00.625 89M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 768 [spades] 0:00:00.626 89M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166471 Gb | |
| 769 [spades] 0:00:00.626 89M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 58185 | |
| 770 [spades] 0:00:00.681 2G / 2G INFO General (edge_index_builders.hpp : 82) Used 14 sequences. | |
| 771 [spades] 0:00:00.688 100M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 772 [spades] 0:00:00.704 100M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 1720 kmers in total. | |
| 773 [spades] 0:00:00.704 100M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 774 [spades] 0:00:00.709 100M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 775 [spades] 0:00:00.728 100M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 776 [spades] 0:00:00.729 100M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 10088 bytes occupied (46.9209 bits per kmer). | |
| 777 [spades] 0:00:00.730 100M / 2G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. | |
| 778 [spades] 0:00:00.733 100M / 2G INFO General (edge_index.hpp : 92) Index refilled | |
| 779 [spades] 0:00:00.735 100M / 2G INFO General (gap_closer.cpp : 147) Preparing shift maps | |
| 780 [spades] 0:00:00.735 100M / 2G INFO General (gap_closer.cpp : 107) Processing paired reads (takes a while) | |
| 781 [spades] 0:00:00.738 100M / 2G INFO General (gap_closer.cpp : 126) Used 23 paired reads | |
| 782 [spades] 0:00:00.739 100M / 2G INFO General (gap_closer.cpp : 128) Merging paired indices | |
| 783 [spades] 0:00:00.739 100M / 2G INFO GapCloser (gap_closer.cpp : 332) Closing short gaps | |
| 784 [spades] 0:00:00.739 100M / 2G INFO GapCloser (gap_closer.cpp : 364) Closing short gaps complete: filled 0 gaps after checking 0 candidates | |
| 785 [spades] 0:00:00.743 100M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification Cleanup | |
| 786 [spades] 0:00:00.744 100M / 2G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification | |
| 787 [spades] 0:00:00.744 100M / 2G INFO General (graph_simplification.hpp : 456) Disconnection of relatively low covered edges disabled | |
| 788 [spades] 0:00:00.744 100M / 2G INFO General (graph_simplification.hpp : 493) Complex tip clipping disabled | |
| 789 [spades] 0:00:00.744 100M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 790 [spades] 0:00:00.745 100M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 791 [spades] 0:00:00.748 100M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 792 [spades] 0:00:00.748 100M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 793 [spades] 0:00:00.753 100M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 794 [spades] 0:00:00.753 100M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 795 [spades] 0:00:00.760 100M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 796 [spades] 0:00:00.761 100M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 797 [spades] 0:00:00.766 100M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 798 [spades] 0:00:00.766 100M / 2G INFO General (simplification.cpp : 343) Disrupting self-conjugate edges | |
| 799 [spades] 0:00:00.766 100M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges | |
| 800 [spades] 0:00:00.770 100M / 2G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 6 times | |
| 801 [spades] 0:00:00.770 100M / 2G INFO General (simplification.cpp : 496) Counting average coverage | |
| 802 [spades] 0:00:00.770 100M / 2G INFO General (simplification.cpp : 502) Average coverage = 39.6025 | |
| 803 [spades] 0:00:00.770 100M / 2G INFO StageManager (stage.cpp : 166) STAGE == Contig Output | |
| 804 [spades] 0:00:00.771 100M / 2G INFO General (read_converter.cpp : 102) Outputting contigs to /home/piemari/shovill_bam/spades/K71/simplified_contigs | |
| 805 [spades] 0:00:00.775 100M / 2G INFO General (binary_converter.cpp : 111) 1 reads written | |
| 806 [spades] 0:00:00.780 100M / 2G INFO General (pipeline.cpp : 259) SPAdes finished | |
| 807 [spades] 0:00:00.781 100M / 2G INFO General (main.cpp : 107) Assembling time: 0 hours 0 minutes 0 seconds | |
| 808 [spades] | |
| 809 [spades] ===== K71 finished. | |
| 810 [spades] | |
| 811 [spades] | |
| 812 [spades] ===== K91 started. | |
| 813 [spades] | |
| 814 [spades] | |
| 815 [spades] == Running: /home/piemari/apps/conda/envs/metaphlan/bin/spades-core /home/piemari/shovill_bam/spades/K91/configs/config.info /home/piemari/shovill_bam/spades/K91/configs/isolate_mode.info | |
| 816 [spades] | |
| 817 [spades] WARNING: Try to use logger before create one. Level=INFO. Message=Additional contigs is /home/piemari/shovill_bam/spades/K71/simplified_contigs | |
| 818 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K91/configs/config.info | |
| 819 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K91/configs/isolate_mode.info | |
| 820 [spades] 0:00:00.000 4M / 10M INFO General (memory_limit.cpp : 49) Memory limit set to 4 Gb | |
| 821 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 85) Starting SPAdes, built from N/A, git revision N/A | |
| 822 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 86) Maximum k-mer length: 128 | |
| 823 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 87) Assembling dataset (/home/piemari/shovill_bam/spades/dataset.info) with K=91 | |
| 824 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 88) Maximum # of threads to use (adjusted due to OMP capabilities): 8 | |
| 825 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 194) SPAdes started | |
| 826 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 201) Starting from stage: read_conversion | |
| 827 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 207) Two-step RR enabled: 0 | |
| 828 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 218) Will need read mapping, kmer mapper will be attached | |
| 829 [spades] 0:00:00.000 4M / 10M INFO StageManager (stage.cpp : 166) STAGE == Binary Read Conversion | |
| 830 [spades] 0:00:00.002 4M / 12M INFO General (read_converter.cpp : 53) Binary reads detected | |
| 831 [spades] 0:00:00.003 4M / 16M INFO StageManager (stage.cpp : 166) STAGE == de Bruijn graph construction | |
| 832 [spades] 0:00:00.003 4M / 16M INFO General (construction.cpp : 115) Contigs from previous K will be used: /home/piemari/shovill_bam/spades/K71/simplified_contigs | |
| 833 [spades] 0:00:00.014 4M / 16M INFO General (construction.cpp : 150) Max read length 280 | |
| 834 [spades] 0:00:00.014 4M / 16M INFO General (construction.cpp : 153) Max read length without merged 150 | |
| 835 [spades] 0:00:00.014 4M / 16M INFO General (construction.cpp : 156) Average read length 193.032 | |
| 836 [spades] 0:00:00.014 4M / 16M INFO General (stage.cpp : 113) PROCEDURE == k+1-mer counting | |
| 837 [spades] 0:00:00.014 4M / 16M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. | |
| 838 [spades] 0:00:00.014 4M / 16M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 839 [spades] 0:00:00.014 4M / 16M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166632 Gb | |
| 840 [spades] 0:00:00.015 4M / 16M INFO General (kmer_splitters.hpp : 97) Using cell size of 116484 | |
| 841 [spades] 0:00:00.092 83M / 554M INFO General (kmer_splitters.hpp : 293) Used 868 reads | |
| 842 [spades] 0:00:00.092 83M / 554M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 843 [spades] 0:00:00.104 83M / 554M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8793 kmers in total. | |
| 844 [spades] 0:00:00.105 83M / 554M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 845 [spades] 0:00:00.108 83M / 554M INFO General (stage.cpp : 113) PROCEDURE == Extension index construction | |
| 846 [spades] 0:00:00.108 83M / 554M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 847 [spades] 0:00:00.108 83M / 554M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 848 [spades] 0:00:00.108 83M / 554M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 849 [spades] 0:00:00.108 83M / 554M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166534 Gb | |
| 850 [spades] 0:00:00.108 83M / 554M INFO General (kmer_splitters.hpp : 97) Using cell size of 58208 | |
| 851 [spades] 0:00:00.181 2G / 2G INFO General (kmer_splitters.hpp : 364) Processed 8793 kmers | |
| 852 [spades] 0:00:00.181 2G / 2G INFO General (kmer_splitters.hpp : 369) Used 8793 kmers. | |
| 853 [spades] 0:00:00.204 98M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 854 [spades] 0:00:00.221 98M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8798 kmers in total. | |
| 855 [spades] 0:00:00.221 98M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 856 [spades] 0:00:00.227 98M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 857 [spades] 0:00:00.250 96M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 858 [spades] 0:00:00.252 96M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13136 bytes occupied (11.9445 bits per kmer). | |
| 859 [spades] 0:00:00.252 96M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers | |
| 860 [spades] 0:00:00.256 96M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. | |
| 861 [spades] 0:00:00.256 96M / 2G INFO General (stage.cpp : 113) PROCEDURE == Condensing graph | |
| 862 [spades] 0:00:00.256 96M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths | |
| 863 [spades] 0:00:00.262 96M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 294 sequences extracted | |
| 864 [spades] 0:00:00.263 96M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops | |
| 865 [spades] 0:00:00.264 96M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 0 loops collected | |
| 866 [spades] 0:00:00.265 96M / 2G INFO General (stage.cpp : 113) PROCEDURE == Filling coverage indices (PHM) | |
| 867 [spades] 0:00:00.265 96M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 868 [spades] 0:00:00.265 96M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 869 [spades] 0:00:00.276 97M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 8576 bytes occupied (7.80257 bits per kmer). | |
| 870 [spades] 0:00:00.276 97M / 2G INFO General (construction.cpp : 429) Collecting k-mer coverage information from reads, this takes a while. | |
| 871 [spades] 0:00:00.280 97M / 2G INFO General (construction.cpp : 549) Filling coverage and flanking coverage from PHM | |
| 872 [spades] 0:00:00.282 97M / 2G INFO StageManager (stage.cpp : 166) STAGE == EC Threshold Finding | |
| 873 [spades] 0:00:00.282 97M / 2G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 | |
| 874 [spades] 0:00:00.283 97M / 2G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 32 | |
| 875 [spades] 0:00:00.283 97M / 2G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 33. Coverage mad: 5.9304 | |
| 876 [spades] 0:00:00.283 97M / 2G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model | |
| 877 [spades] 0:00:00.289 97M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 | |
| 878 [spades] 0:00:00.304 97M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 | |
| 879 [spades] 0:00:00.356 97M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 | |
| 880 [spades] 0:00:00.392 97M / 2G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 33.4369. Fitted coverage std. dev: 4.99367 | |
| 881 [spades] 0:00:00.392 97M / 2G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 1 | |
| 882 [spades] 0:00:00.393 97M / 2G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 23 | |
| 883 [spades] 0:00:00.393 97M / 2G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 17 | |
| 884 [spades] 0:00:00.393 97M / 2G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 1078 | |
| 885 [spades] 0:00:00.393 97M / 2G INFO General (genomic_info_filler.cpp : 53) Mean coverage was calculated as 33.4369 | |
| 886 [spades] 0:00:00.393 97M / 2G INFO General (genomic_info_filler.cpp : 68) EC coverage threshold value was calculated as 17 | |
| 887 [spades] 0:00:00.393 97M / 2G INFO General (genomic_info_filler.cpp : 69) Trusted kmer low bound: 0 | |
| 888 [spades] 0:00:00.394 97M / 2G INFO StageManager (stage.cpp : 166) STAGE == Gap Closer | |
| 889 [spades] 0:00:00.394 97M / 2G INFO General (graph_pack.hpp : 105) Index refill | |
| 890 [spades] 0:00:00.394 97M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 891 [spades] 0:00:00.394 97M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 892 [spades] 0:00:00.394 97M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 893 [spades] 0:00:00.395 97M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166468 Gb | |
| 894 [spades] 0:00:00.395 97M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 58184 | |
| 895 [spades] 0:00:00.459 2G / 2G INFO General (edge_index_builders.hpp : 82) Used 588 sequences. | |
| 896 [spades] 0:00:00.476 113M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 897 [spades] 0:00:00.494 113M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8793 kmers in total. | |
| 898 [spades] 0:00:00.495 113M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 899 [spades] 0:00:00.501 113M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 900 [spades] 0:00:00.521 113M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 901 [spades] 0:00:00.523 113M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13144 bytes occupied (11.9586 bits per kmer). | |
| 902 [spades] 0:00:00.523 113M / 2G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. | |
| 903 [spades] 0:00:00.527 113M / 2G INFO General (edge_index.hpp : 92) Index refilled | |
| 904 [spades] 0:00:00.529 113M / 2G INFO General (gap_closer.cpp : 147) Preparing shift maps | |
| 905 [spades] 0:00:00.529 113M / 2G INFO General (gap_closer.cpp : 107) Processing paired reads (takes a while) | |
| 906 [spades] 0:00:00.532 113M / 2G INFO General (gap_closer.cpp : 126) Used 23 paired reads | |
| 907 [spades] 0:00:00.532 113M / 2G INFO General (gap_closer.cpp : 128) Merging paired indices | |
| 908 [spades] 0:00:00.533 113M / 2G INFO GapCloser (gap_closer.cpp : 332) Closing short gaps | |
| 909 [spades] 0:00:00.533 113M / 2G INFO GapCloser (gap_closer.cpp : 364) Closing short gaps complete: filled 0 gaps after checking 0 candidates | |
| 910 [spades] 0:00:00.537 113M / 2G INFO StageManager (stage.cpp : 166) STAGE == Raw Simplification | |
| 911 [spades] 0:00:00.538 113M / 2G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning | |
| 912 [spades] 0:00:00.538 113M / 2G INFO General (graph_simplification.hpp : 671) Flanking coverage based disconnection disabled | |
| 913 [spades] 0:00:00.538 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover | |
| 914 [spades] 0:00:00.543 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times | |
| 915 [spades] 0:00:00.543 113M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification | |
| 916 [spades] 0:00:00.544 113M / 2G INFO General (simplification.cpp : 383) Graph simplification started | |
| 917 [spades] 0:00:00.544 113M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 918 [spades] 0:00:00.544 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 1 | |
| 919 [spades] 0:00:00.545 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 920 [spades] 0:00:00.549 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 132 times | |
| 921 [spades] 0:00:00.550 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 922 [spades] 0:00:00.555 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 8 times | |
| 923 [spades] 0:00:00.555 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 924 [spades] 0:00:00.558 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 925 [spades] 0:00:00.559 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 2 | |
| 926 [spades] 0:00:00.559 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 927 [spades] 0:00:00.559 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 928 [spades] 0:00:00.560 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 929 [spades] 0:00:00.560 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 930 [spades] 0:00:00.560 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 931 [spades] 0:00:00.561 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 932 [spades] 0:00:00.561 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 3 | |
| 933 [spades] 0:00:00.561 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 934 [spades] 0:00:00.561 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 935 [spades] 0:00:00.561 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 936 [spades] 0:00:00.562 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 937 [spades] 0:00:00.562 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 938 [spades] 0:00:00.562 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 939 [spades] 0:00:00.562 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 4 | |
| 940 [spades] 0:00:00.562 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 941 [spades] 0:00:00.563 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 942 [spades] 0:00:00.563 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 943 [spades] 0:00:00.563 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 944 [spades] 0:00:00.563 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 945 [spades] 0:00:00.563 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 946 [spades] 0:00:00.564 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 5 | |
| 947 [spades] 0:00:00.564 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 948 [spades] 0:00:00.564 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 949 [spades] 0:00:00.564 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 950 [spades] 0:00:00.564 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 951 [spades] 0:00:00.565 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 952 [spades] 0:00:00.565 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 953 [spades] 0:00:00.565 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 6 | |
| 954 [spades] 0:00:00.565 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 955 [spades] 0:00:00.566 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 956 [spades] 0:00:00.566 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 957 [spades] 0:00:00.566 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 958 [spades] 0:00:00.566 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 959 [spades] 0:00:00.566 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 960 [spades] 0:00:00.567 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 7 | |
| 961 [spades] 0:00:00.567 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 962 [spades] 0:00:00.567 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 963 [spades] 0:00:00.567 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 964 [spades] 0:00:00.567 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 965 [spades] 0:00:00.568 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 966 [spades] 0:00:00.568 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 967 [spades] 0:00:00.568 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 8 | |
| 968 [spades] 0:00:00.568 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 969 [spades] 0:00:00.568 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 970 [spades] 0:00:00.569 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 971 [spades] 0:00:00.569 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 972 [spades] 0:00:00.569 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 973 [spades] 0:00:00.569 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 974 [spades] 0:00:00.569 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 9 | |
| 975 [spades] 0:00:00.570 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 976 [spades] 0:00:00.570 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 977 [spades] 0:00:00.570 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 978 [spades] 0:00:00.570 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 979 [spades] 0:00:00.570 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 980 [spades] 0:00:00.571 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 981 [spades] 0:00:00.571 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 10 | |
| 982 [spades] 0:00:00.571 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 983 [spades] 0:00:00.571 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 984 [spades] 0:00:00.571 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 985 [spades] 0:00:00.572 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 986 [spades] 0:00:00.572 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 987 [spades] 0:00:00.572 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 988 [spades] 0:00:00.572 113M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 11 | |
| 989 [spades] 0:00:00.573 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 990 [spades] 0:00:00.574 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 991 [spades] 0:00:00.574 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 992 [spades] 0:00:00.576 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 993 [spades] 0:00:00.576 113M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 994 [spades] 0:00:00.577 113M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 995 [spades] 0:00:00.577 113M / 2G INFO StageManager (stage.cpp : 166) STAGE == Gap Closer | |
| 996 [spades] 0:00:00.577 113M / 2G INFO General (graph_pack.hpp : 105) Index refill | |
| 997 [spades] 0:00:00.578 113M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 998 [spades] 0:00:00.578 113M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 999 [spades] 0:00:00.579 113M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 1000 [spades] 0:00:00.579 113M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166448 Gb | |
| 1001 [spades] 0:00:00.579 113M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 58177 | |
| 1002 [spades] 0:00:00.641 2G / 2G INFO General (edge_index_builders.hpp : 82) Used 26 sequences. | |
| 1003 [spades] 0:00:00.649 121M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 1004 [spades] 0:00:00.665 121M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 2088 kmers in total. | |
| 1005 [spades] 0:00:00.665 121M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 1006 [spades] 0:00:00.670 121M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 1007 [spades] 0:00:00.688 121M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 1008 [spades] 0:00:00.689 121M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 10200 bytes occupied (39.0805 bits per kmer). | |
| 1009 [spades] 0:00:00.690 121M / 2G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. | |
| 1010 [spades] 0:00:00.693 121M / 2G INFO General (edge_index.hpp : 92) Index refilled | |
| 1011 [spades] 0:00:00.695 121M / 2G INFO General (gap_closer.cpp : 147) Preparing shift maps | |
| 1012 [spades] 0:00:00.696 121M / 2G INFO General (gap_closer.cpp : 107) Processing paired reads (takes a while) | |
| 1013 [spades] 0:00:00.698 121M / 2G INFO General (gap_closer.cpp : 126) Used 23 paired reads | |
| 1014 [spades] 0:00:00.699 121M / 2G INFO General (gap_closer.cpp : 128) Merging paired indices | |
| 1015 [spades] 0:00:00.699 121M / 2G INFO GapCloser (gap_closer.cpp : 332) Closing short gaps | |
| 1016 [spades] 0:00:00.699 121M / 2G INFO GapCloser (gap_closer.cpp : 364) Closing short gaps complete: filled 0 gaps after checking 0 candidates | |
| 1017 [spades] 0:00:00.703 121M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification Cleanup | |
| 1018 [spades] 0:00:00.704 121M / 2G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification | |
| 1019 [spades] 0:00:00.704 121M / 2G INFO General (graph_simplification.hpp : 456) Disconnection of relatively low covered edges disabled | |
| 1020 [spades] 0:00:00.705 121M / 2G INFO General (graph_simplification.hpp : 493) Complex tip clipping disabled | |
| 1021 [spades] 0:00:00.705 121M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 1022 [spades] 0:00:00.705 121M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1023 [spades] 0:00:00.708 121M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1024 [spades] 0:00:00.709 121M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1025 [spades] 0:00:00.713 121M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1026 [spades] 0:00:00.714 121M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1027 [spades] 0:00:00.718 121M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1028 [spades] 0:00:00.719 121M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1029 [spades] 0:00:00.720 121M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1030 [spades] 0:00:00.720 121M / 2G INFO General (simplification.cpp : 343) Disrupting self-conjugate edges | |
| 1031 [spades] 0:00:00.721 121M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges | |
| 1032 [spades] 0:00:00.722 121M / 2G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 12 times | |
| 1033 [spades] 0:00:00.722 121M / 2G INFO General (simplification.cpp : 496) Counting average coverage | |
| 1034 [spades] 0:00:00.723 121M / 2G INFO General (simplification.cpp : 502) Average coverage = 31.9224 | |
| 1035 [spades] 0:00:00.723 121M / 2G INFO StageManager (stage.cpp : 166) STAGE == Contig Output | |
| 1036 [spades] 0:00:00.724 121M / 2G INFO General (read_converter.cpp : 102) Outputting contigs to /home/piemari/shovill_bam/spades/K91/simplified_contigs | |
| 1037 [spades] 0:00:00.727 121M / 2G INFO General (binary_converter.cpp : 111) 1 reads written | |
| 1038 [spades] 0:00:00.732 121M / 2G INFO General (pipeline.cpp : 259) SPAdes finished | |
| 1039 [spades] 0:00:00.733 121M / 2G INFO General (main.cpp : 107) Assembling time: 0 hours 0 minutes 0 seconds | |
| 1040 [spades] | |
| 1041 [spades] ===== K91 finished. | |
| 1042 [spades] | |
| 1043 [spades] | |
| 1044 [spades] ===== K111 started. | |
| 1045 [spades] | |
| 1046 [spades] | |
| 1047 [spades] == Running: /home/piemari/apps/conda/envs/metaphlan/bin/spades-core /home/piemari/shovill_bam/spades/K111/configs/config.info /home/piemari/shovill_bam/spades/K111/configs/isolate_mode.info | |
| 1048 [spades] | |
| 1049 [spades] WARNING: Try to use logger before create one. Level=INFO. Message=Additional contigs is /home/piemari/shovill_bam/spades/K91/simplified_contigs | |
| 1050 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K111/configs/config.info | |
| 1051 [spades] 0:00:00.000 4M / 9M INFO General (main.cpp : 75) Loaded config from /home/piemari/shovill_bam/spades/K111/configs/isolate_mode.info | |
| 1052 [spades] 0:00:00.000 4M / 10M INFO General (memory_limit.cpp : 49) Memory limit set to 4 Gb | |
| 1053 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 85) Starting SPAdes, built from N/A, git revision N/A | |
| 1054 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 86) Maximum k-mer length: 128 | |
| 1055 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 87) Assembling dataset (/home/piemari/shovill_bam/spades/dataset.info) with K=111 | |
| 1056 [spades] 0:00:00.000 4M / 10M INFO General (main.cpp : 88) Maximum # of threads to use (adjusted due to OMP capabilities): 8 | |
| 1057 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 194) SPAdes started | |
| 1058 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 201) Starting from stage: read_conversion | |
| 1059 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 207) Two-step RR enabled: 0 | |
| 1060 [spades] 0:00:00.000 4M / 10M INFO General (pipeline.cpp : 218) Will need read mapping, kmer mapper will be attached | |
| 1061 [spades] 0:00:00.000 4M / 10M INFO StageManager (stage.cpp : 166) STAGE == Binary Read Conversion | |
| 1062 [spades] 0:00:00.001 4M / 12M INFO General (read_converter.cpp : 53) Binary reads detected | |
| 1063 [spades] 0:00:00.002 4M / 16M INFO StageManager (stage.cpp : 166) STAGE == de Bruijn graph construction | |
| 1064 [spades] 0:00:00.002 4M / 16M INFO General (construction.cpp : 115) Contigs from previous K will be used: /home/piemari/shovill_bam/spades/K91/simplified_contigs | |
| 1065 [spades] 0:00:00.007 4M / 16M INFO General (construction.cpp : 150) Max read length 280 | |
| 1066 [spades] 0:00:00.007 4M / 16M INFO General (construction.cpp : 153) Max read length without merged 150 | |
| 1067 [spades] 0:00:00.007 4M / 16M INFO General (construction.cpp : 156) Average read length 193.032 | |
| 1068 [spades] 0:00:00.007 4M / 16M INFO General (stage.cpp : 113) PROCEDURE == k+1-mer counting | |
| 1069 [spades] 0:00:00.007 4M / 16M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 64 files using 8 threads. This might take a while. | |
| 1070 [spades] 0:00:00.007 4M / 16M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 1071 [spades] 0:00:00.007 4M / 16M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166632 Gb | |
| 1072 [spades] 0:00:00.007 4M / 16M INFO General (kmer_splitters.hpp : 97) Using cell size of 87363 | |
| 1073 [spades] 0:00:00.085 83M / 552M INFO General (kmer_splitters.hpp : 293) Used 868 reads | |
| 1074 [spades] 0:00:00.085 83M / 552M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 1075 [spades] 0:00:00.101 83M / 552M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8451 kmers in total. | |
| 1076 [spades] 0:00:00.101 83M / 552M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 1077 [spades] 0:00:00.105 83M / 552M INFO General (stage.cpp : 113) PROCEDURE == Extension index construction | |
| 1078 [spades] 0:00:00.105 83M / 552M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 1079 [spades] 0:00:00.105 83M / 552M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 1080 [spades] 0:00:00.105 83M / 552M INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 1081 [spades] 0:00:00.105 83M / 552M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166533 Gb | |
| 1082 [spades] 0:00:00.105 83M / 552M INFO General (kmer_splitters.hpp : 97) Using cell size of 43655 | |
| 1083 [spades] 0:00:00.179 2G / 2G INFO General (kmer_splitters.hpp : 364) Processed 8451 kmers | |
| 1084 [spades] 0:00:00.180 2G / 2G INFO General (kmer_splitters.hpp : 369) Used 8451 kmers. | |
| 1085 [spades] 0:00:00.203 97M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 1086 [spades] 0:00:00.220 99M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8478 kmers in total. | |
| 1087 [spades] 0:00:00.220 99M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 1088 [spades] 0:00:00.226 99M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 1089 [spades] 0:00:00.250 96M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 1090 [spades] 0:00:00.252 96M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12992 bytes occupied (12.2595 bits per kmer). | |
| 1091 [spades] 0:00:00.252 96M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers | |
| 1092 [spades] 0:00:00.257 96M / 2G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. | |
| 1093 [spades] 0:00:00.258 96M / 2G INFO General (stage.cpp : 113) PROCEDURE == Condensing graph | |
| 1094 [spades] 0:00:00.258 96M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths | |
| 1095 [spades] 0:00:00.263 97M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 272 sequences extracted | |
| 1096 [spades] 0:00:00.264 97M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops | |
| 1097 [spades] 0:00:00.265 97M / 2G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 0 loops collected | |
| 1098 [spades] 0:00:00.266 97M / 2G INFO General (stage.cpp : 113) PROCEDURE == Filling coverage indices (PHM) | |
| 1099 [spades] 0:00:00.266 97M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 1100 [spades] 0:00:00.267 97M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 1101 [spades] 0:00:00.280 97M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 8376 bytes occupied (7.929 bits per kmer). | |
| 1102 [spades] 0:00:00.280 97M / 2G INFO General (construction.cpp : 429) Collecting k-mer coverage information from reads, this takes a while. | |
| 1103 [spades] 0:00:00.284 97M / 2G INFO General (construction.cpp : 549) Filling coverage and flanking coverage from PHM | |
| 1104 [spades] 0:00:00.290 97M / 2G INFO StageManager (stage.cpp : 166) STAGE == EC Threshold Finding | |
| 1105 [spades] 0:00:00.291 97M / 2G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 | |
| 1106 [spades] 0:00:00.291 97M / 2G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 28 | |
| 1107 [spades] 0:00:00.291 97M / 2G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 28. Coverage mad: 5.9304 | |
| 1108 [spades] 0:00:00.291 97M / 2G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model | |
| 1109 [spades] 0:00:00.297 97M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 | |
| 1110 [spades] 0:00:00.310 97M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 | |
| 1111 [spades] 0:00:00.342 97M / 2G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 | |
| 1112 [spades] 0:00:00.373 97M / 2G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 26.1152. Fitted coverage std. dev: 4.16511 | |
| 1113 [spades] 0:00:00.373 97M / 2G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.999998 | |
| 1114 [spades] 0:00:00.374 97M / 2G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 18 | |
| 1115 [spades] 0:00:00.374 97M / 2G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 14 | |
| 1116 [spades] 0:00:00.374 97M / 2G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 1059 | |
| 1117 [spades] 0:00:00.374 97M / 2G INFO General (genomic_info_filler.cpp : 53) Mean coverage was calculated as 26.1152 | |
| 1118 [spades] 0:00:00.374 97M / 2G INFO General (genomic_info_filler.cpp : 68) EC coverage threshold value was calculated as 14 | |
| 1119 [spades] 0:00:00.374 97M / 2G INFO General (genomic_info_filler.cpp : 69) Trusted kmer low bound: 0 | |
| 1120 [spades] 0:00:00.375 97M / 2G INFO StageManager (stage.cpp : 166) STAGE == Gap Closer | |
| 1121 [spades] 0:00:00.375 97M / 2G INFO General (graph_pack.hpp : 105) Index refill | |
| 1122 [spades] 0:00:00.375 97M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 1123 [spades] 0:00:00.375 97M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 1124 [spades] 0:00:00.375 97M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 1125 [spades] 0:00:00.376 97M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166477 Gb | |
| 1126 [spades] 0:00:00.376 97M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 43640 | |
| 1127 [spades] 0:00:00.444 2G / 2G INFO General (edge_index_builders.hpp : 82) Used 544 sequences. | |
| 1128 [spades] 0:00:00.465 105M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 1129 [spades] 0:00:00.487 105M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 8451 kmers in total. | |
| 1130 [spades] 0:00:00.487 105M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 1131 [spades] 0:00:00.493 105M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 1132 [spades] 0:00:00.513 106M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 1133 [spades] 0:00:00.515 106M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12976 bytes occupied (12.2835 bits per kmer). | |
| 1134 [spades] 0:00:00.515 106M / 2G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. | |
| 1135 [spades] 0:00:00.518 106M / 2G INFO General (edge_index.hpp : 92) Index refilled | |
| 1136 [spades] 0:00:00.524 106M / 2G INFO General (gap_closer.cpp : 147) Preparing shift maps | |
| 1137 [spades] 0:00:00.525 106M / 2G INFO General (gap_closer.cpp : 107) Processing paired reads (takes a while) | |
| 1138 [spades] 0:00:00.527 106M / 2G INFO General (gap_closer.cpp : 126) Used 23 paired reads | |
| 1139 [spades] 0:00:00.527 106M / 2G INFO General (gap_closer.cpp : 128) Merging paired indices | |
| 1140 [spades] 0:00:00.527 106M / 2G INFO GapCloser (gap_closer.cpp : 332) Closing short gaps | |
| 1141 [spades] 0:00:00.528 106M / 2G INFO GapCloser (gap_closer.cpp : 364) Closing short gaps complete: filled 0 gaps after checking 0 candidates | |
| 1142 [spades] 0:00:00.528 106M / 2G INFO StageManager (stage.cpp : 166) STAGE == Raw Simplification | |
| 1143 [spades] 0:00:00.529 106M / 2G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning | |
| 1144 [spades] 0:00:00.529 106M / 2G INFO General (simplification.cpp : 63) Most init cleaning disabled on main iteration | |
| 1145 [spades] 0:00:00.530 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover | |
| 1146 [spades] 0:00:00.530 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times | |
| 1147 [spades] 0:00:00.530 106M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification | |
| 1148 [spades] 0:00:00.531 106M / 2G INFO General (simplification.cpp : 383) Graph simplification started | |
| 1149 [spades] 0:00:00.531 106M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 1150 [spades] 0:00:00.531 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 1 | |
| 1151 [spades] 0:00:00.532 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1152 [spades] 0:00:00.533 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 114 times | |
| 1153 [spades] 0:00:00.534 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1154 [spades] 0:00:00.536 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 5 times | |
| 1155 [spades] 0:00:00.536 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1156 [spades] 0:00:00.537 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1157 [spades] 0:00:00.537 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 2 | |
| 1158 [spades] 0:00:00.537 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1159 [spades] 0:00:00.538 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1160 [spades] 0:00:00.538 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1161 [spades] 0:00:00.538 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1162 [spades] 0:00:00.539 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1163 [spades] 0:00:00.539 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1164 [spades] 0:00:00.539 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 3 | |
| 1165 [spades] 0:00:00.539 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1166 [spades] 0:00:00.540 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1167 [spades] 0:00:00.540 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1168 [spades] 0:00:00.540 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1169 [spades] 0:00:00.540 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1170 [spades] 0:00:00.540 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1171 [spades] 0:00:00.541 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 4 | |
| 1172 [spades] 0:00:00.541 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1173 [spades] 0:00:00.541 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1174 [spades] 0:00:00.541 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1175 [spades] 0:00:00.541 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1176 [spades] 0:00:00.542 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1177 [spades] 0:00:00.542 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1178 [spades] 0:00:00.542 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 5 | |
| 1179 [spades] 0:00:00.542 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1180 [spades] 0:00:00.542 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1181 [spades] 0:00:00.543 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1182 [spades] 0:00:00.543 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1183 [spades] 0:00:00.543 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1184 [spades] 0:00:00.543 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1185 [spades] 0:00:00.543 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 6 | |
| 1186 [spades] 0:00:00.544 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1187 [spades] 0:00:00.544 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1188 [spades] 0:00:00.544 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1189 [spades] 0:00:00.544 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1190 [spades] 0:00:00.544 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1191 [spades] 0:00:00.545 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1192 [spades] 0:00:00.545 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 7 | |
| 1193 [spades] 0:00:00.545 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1194 [spades] 0:00:00.545 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1195 [spades] 0:00:00.545 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1196 [spades] 0:00:00.546 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1197 [spades] 0:00:00.546 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1198 [spades] 0:00:00.546 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1199 [spades] 0:00:00.546 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 8 | |
| 1200 [spades] 0:00:00.546 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1201 [spades] 0:00:00.547 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1202 [spades] 0:00:00.547 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1203 [spades] 0:00:00.547 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1204 [spades] 0:00:00.547 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1205 [spades] 0:00:00.547 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1206 [spades] 0:00:00.548 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 9 | |
| 1207 [spades] 0:00:00.548 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1208 [spades] 0:00:00.548 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1209 [spades] 0:00:00.548 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1210 [spades] 0:00:00.548 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1211 [spades] 0:00:00.549 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1212 [spades] 0:00:00.549 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1213 [spades] 0:00:00.549 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 10 | |
| 1214 [spades] 0:00:00.549 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1215 [spades] 0:00:00.549 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1216 [spades] 0:00:00.550 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1217 [spades] 0:00:00.550 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1218 [spades] 0:00:00.550 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1219 [spades] 0:00:00.550 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1220 [spades] 0:00:00.550 106M / 2G INFO General (simplification.cpp : 388) PROCEDURE == Simplification cycle, iteration 11 | |
| 1221 [spades] 0:00:00.551 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1222 [spades] 0:00:00.553 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1223 [spades] 0:00:00.554 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1224 [spades] 0:00:00.558 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1225 [spades] 0:00:00.559 106M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover | |
| 1226 [spades] 0:00:00.564 106M / 2G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times | |
| 1227 [spades] 0:00:00.568 106M / 2G INFO StageManager (stage.cpp : 166) STAGE == Gap Closer | |
| 1228 [spades] 0:00:00.569 106M / 2G INFO General (graph_pack.hpp : 105) Index refill | |
| 1229 [spades] 0:00:00.569 106M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index | |
| 1230 [spades] 0:00:00.569 106M / 2G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 128 files using 8 threads. This might take a while. | |
| 1231 [spades] 0:00:00.570 106M / 2G INFO General (file_limit.hpp : 32) Open file limit set to 131072 | |
| 1232 [spades] 0:00:00.570 106M / 2G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 0.166454 Gb | |
| 1233 [spades] 0:00:00.570 106M / 2G INFO General (kmer_splitters.hpp : 97) Using cell size of 43635 | |
| 1234 [spades] 0:00:00.631 2G / 2G INFO General (edge_index_builders.hpp : 82) Used 64 sequences. | |
| 1235 [spades] 0:00:00.641 119M / 2G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. | |
| 1236 [spades] 0:00:00.656 119M / 2G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 3182 kmers in total. | |
| 1237 [spades] 0:00:00.656 119M / 2G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. | |
| 1238 [spades] 0:00:00.661 119M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices | |
| 1239 [spades] 0:00:00.681 119M / 2G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. | |
| 1240 [spades] 0:00:00.682 119M / 2G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 10600 bytes occupied (26.6499 bits per kmer). | |
| 1241 [spades] 0:00:00.683 119M / 2G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. | |
| 1242 [spades] 0:00:00.686 119M / 2G INFO General (edge_index.hpp : 92) Index refilled | |
| 1243 [spades] 0:00:00.689 119M / 2G INFO General (gap_closer.cpp : 147) Preparing shift maps | |
| 1244 [spades] 0:00:00.689 119M / 2G INFO General (gap_closer.cpp : 107) Processing paired reads (takes a while) | |
| 1245 [spades] 0:00:00.691 119M / 2G INFO General (gap_closer.cpp : 126) Used 23 paired reads | |
| 1246 [spades] 0:00:00.692 119M / 2G INFO General (gap_closer.cpp : 128) Merging paired indices | |
| 1247 [spades] 0:00:00.692 119M / 2G INFO GapCloser (gap_closer.cpp : 332) Closing short gaps | |
| 1248 [spades] 0:00:00.693 119M / 2G INFO GapCloser (gap_closer.cpp : 364) Closing short gaps complete: filled 0 gaps after checking 0 candidates | |
| 1249 [spades] 0:00:00.693 119M / 2G INFO StageManager (stage.cpp : 166) STAGE == Simplification Cleanup | |
| 1250 [spades] 0:00:00.694 119M / 2G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification | |
| 1251 [spades] 0:00:00.694 119M / 2G INFO General (graph_simplification.hpp : 456) Disconnection of relatively low covered edges disabled | |
| 1252 [spades] 0:00:00.694 119M / 2G INFO General (graph_simplification.hpp : 493) Complex tip clipping disabled | |
| 1253 [spades] 0:00:00.695 119M / 2G INFO General (graph_simplification.hpp : 643) Creating parallel br instance | |
| 1254 [spades] 0:00:00.695 119M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1255 [spades] 0:00:00.695 119M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1256 [spades] 0:00:00.696 119M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1257 [spades] 0:00:00.696 119M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1258 [spades] 0:00:00.697 119M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper | |
| 1259 [spades] 0:00:00.697 119M / 2G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times | |
| 1260 [spades] 0:00:00.697 119M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover | |
| 1261 [spades] 0:00:00.698 119M / 2G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times | |
| 1262 [spades] 0:00:00.698 119M / 2G INFO General (simplification.cpp : 343) Disrupting self-conjugate edges | |
| 1263 [spades] 0:00:00.698 119M / 2G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges | |
| 1264 [spades] 0:00:00.700 119M / 2G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 31 times | |
| 1265 [spades] 0:00:00.701 119M / 2G INFO General (simplification.cpp : 496) Counting average coverage | |
| 1266 [spades] 0:00:00.701 119M / 2G INFO General (simplification.cpp : 502) Average coverage = 25.1649 | |
| 1267 [spades] 0:00:00.701 119M / 2G INFO StageManager (stage.cpp : 166) STAGE == Mismatch Correction | |
| 1268 [spades] 0:00:00.701 119M / 2G INFO General (graph_pack.hpp : 113) Normalizing k-mer map. Total 1220 kmers to process | |
| 1269 [spades] 0:00:00.702 119M / 2G INFO General (graph_pack.hpp : 115) Normalizing done | |
| 1270 [spades] 0:00:00.714 119M / 2G INFO General (mismatch_shall_not_pass.hp: 195) Finished collecting potential mismatches positions | |
| 1271 [spades] 0:00:00.714 119M / 2G INFO General (mismatch_shall_not_pass.hp: 310) All edges processed | |
| 1272 [spades] 0:00:00.715 119M / 2G INFO General (mismatch_correction.cpp : 27) Corrected 0 nucleotides | |
| 1273 [spades] 0:00:00.715 119M / 2G INFO StageManager (stage.cpp : 166) STAGE == Contig Output | |
| 1274 [spades] 0:00:00.716 119M / 2G INFO General (contig_output.hpp : 21) Outputting contigs to /home/piemari/shovill_bam/spades/K111/before_rr.fasta | |
| 1275 [spades] 0:00:00.719 119M / 2G INFO General (contig_output_stage.cpp : 146) Writing GFA graph to /home/piemari/shovill_bam/spades/K111/assembly_graph_after_simplification.gfa | |
| 1276 [spades] 0:00:00.719 119M / 2G INFO StageManager (stage.cpp : 166) STAGE == Paired Information Counting | |
| 1277 [spades] 0:00:00.719 119M / 2G INFO General (graph_pack.hpp : 113) Normalizing k-mer map. Total 1220 kmers to process | |
| 1278 [spades] 0:00:00.720 119M / 2G INFO General (graph_pack.hpp : 115) Normalizing done | |
| 1279 [spades] 0:00:00.720 119M / 2G INFO General (pair_info_count.cpp : 322) Min edge length for estimation: 1140 | |
| 1280 [spades] 0:00:00.720 119M / 2G INFO General (pair_info_count.cpp : 333) Estimating insert size for library #0 | |
| 1281 [spades] 0:00:00.720 119M / 2G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) | |
| 1282 [spades] 0:00:00.763 263M / 2G INFO General (pair_info_count.cpp : 39) Selecting usual mapper | |
| 1283 [spades] 0:00:00.967 263M / 2G INFO General (sequence_mapper_notifier.h: 94) Total 410 reads processed | |
| 1284 [spades] 0:00:01.259 263M / 2G INFO General (pair_info_count.cpp : 208) Edge pairs: 2 | |
| 1285 [spades] 0:00:01.261 263M / 2G INFO General (pair_info_count.cpp : 210) 334 paired reads (81.4634% of all) aligned to long edges | |
| 1286 [spades] 0:00:01.263 119M / 2G INFO General (pair_info_count.cpp : 352) Insert size = 201.347, deviation = 42.1646, left quantile = 150, right quantile = 261, read length = 150 | |
| 1287 [spades] 0:00:01.263 119M / 2G INFO General (pair_info_count.cpp : 373) Filtering data for library #0 | |
| 1288 [spades] 0:00:01.266 119M / 2G INFO General (pair_info_count.cpp : 39) Selecting usual mapper | |
| 1289 [spades] 0:00:01.268 119M / 2G INFO General (sequence_mapper_notifier.h: 94) Total 410 reads processed | |
| 1290 [spades] 0:00:01.268 119M / 2G INFO General (pair_info_count.cpp : 385) Mapping library #0 | |
| 1291 [spades] 0:00:01.269 119M / 2G INFO General (pair_info_count.cpp : 387) Mapping paired reads (takes a while) | |
| 1292 [spades] 0:00:01.269 119M / 2G INFO General (pair_info_count.cpp : 285) Left insert size quantile 150, right insert size quantile 261, filtering threshold 2, rounding threshold 0 | |
| 1293 [spades] 0:00:01.277 119M / 2G INFO General (pair_info_count.cpp : 39) Selecting usual mapper | |
| 1294 [spades] 0:00:01.280 119M / 2G INFO General (sequence_mapper_notifier.h: 94) Total 410 reads processed | |
| 1295 [spades] 0:00:01.283 119M / 2G INFO StageManager (stage.cpp : 166) STAGE == Distance Estimation | |
| 1296 [spades] 0:00:01.283 119M / 2G INFO General (distance_estimation.cpp : 174) Processing library #0 | |
| 1297 [spades] 0:00:01.284 119M / 2G INFO General (distance_estimation.cpp : 150) Weight Filter Done | |
| 1298 [spades] 0:00:01.284 119M / 2G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator | |
| 1299 [spades] 0:00:01.286 119M / 2G INFO General (distance_estimation.cpp : 35) Filtering info | |
| 1300 [spades] 0:00:01.287 119M / 2G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2 | |
| 1301 [spades] 0:00:01.287 119M / 2G INFO General (pair_info_filters.hpp : 263) Done filtering | |
| 1302 [spades] 0:00:01.287 119M / 2G INFO General (distance_estimation.cpp : 157) Refining clustered pair information | |
| 1303 [spades] 0:00:01.287 119M / 2G INFO General (distance_estimation.cpp : 159) The refining of clustered pair information has been finished | |
| 1304 [spades] 0:00:01.288 119M / 2G INFO General (distance_estimation.cpp : 161) Improving paired information | |
| 1305 [spades] 0:00:01.288 119M / 2G INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 0; contradictional = 0 | |
| 1306 [spades] 0:00:01.289 119M / 2G INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 0; contradictional = 0 | |
| 1307 [spades] 0:00:01.289 119M / 2G INFO General (distance_estimation.cpp : 104) Filling scaffolding index | |
| 1308 [spades] 0:00:01.290 119M / 2G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator | |
| 1309 [spades] 0:00:01.290 119M / 2G INFO General (distance_estimation.cpp : 35) Filtering info | |
| 1310 [spades] 0:00:01.290 119M / 2G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2 | |
| 1311 [spades] 0:00:01.291 119M / 2G INFO General (pair_info_filters.hpp : 263) Done filtering | |
| 1312 [spades] 0:00:01.291 119M / 2G INFO General (distance_estimation.cpp : 183) Clearing raw paired index | |
| 1313 [spades] 0:00:01.291 119M / 2G INFO StageManager (stage.cpp : 166) STAGE == Repeat Resolving | |
| 1314 [spades] 0:00:01.291 119M / 2G INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving | |
| 1315 [spades] 0:00:01.292 119M / 2G INFO General (launcher.cpp : 538) ExSPAnder repeat resolving tool started | |
| 1316 [spades] 0:00:01.293 119M / 2G INFO General (launcher.cpp : 404) Creating main extenders, unique edge length = 2000 | |
| 1317 [spades] 0:00:01.293 119M / 2G INFO General (extenders_logic.cpp : 311) Estimated coverage of library #0 is 25.1649 | |
| 1318 [spades] 0:00:01.293 119M / 2G INFO General (extenders_logic.cpp : 311) Estimated coverage of library #0 is 25.1649 | |
| 1319 [spades] 0:00:01.294 119M / 2G INFO General (extenders_logic.cpp : 519) Using 1 paired-end library | |
| 1320 [spades] 0:00:01.294 119M / 2G INFO General (extenders_logic.cpp : 520) Using 1 paired-end scaffolding library | |
| 1321 [spades] 0:00:01.294 119M / 2G INFO General (extenders_logic.cpp : 521) Using 0 single read libraries | |
| 1322 [spades] 0:00:01.294 119M / 2G INFO General (launcher.cpp : 432) Total number of extenders is 3 | |
| 1323 [spades] 0:00:01.294 119M / 2G INFO General (launcher.cpp : 244) Finalizing paths | |
| 1324 [spades] 0:00:01.295 119M / 2G INFO General (launcher.cpp : 246) Deduplicating paths | |
| 1325 [spades] 0:00:01.295 119M / 2G INFO General (launcher.cpp : 250) Paths deduplicated | |
| 1326 [spades] 0:00:01.295 119M / 2G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps | |
| 1327 [spades] 0:00:01.295 119M / 2G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths | |
| 1328 [spades] 0:00:01.295 119M / 2G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps | |
| 1329 [spades] 0:00:01.295 119M / 2G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps | |
| 1330 [spades] 0:00:01.296 119M / 2G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps | |
| 1331 [spades] 0:00:01.296 119M / 2G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths | |
| 1332 [spades] 0:00:01.296 119M / 2G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths | |
| 1333 [spades] 0:00:01.296 119M / 2G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed | |
| 1334 [spades] 0:00:01.296 119M / 2G INFO General (launcher.cpp : 267) Paths finalized | |
| 1335 [spades] 0:00:01.296 119M / 2G INFO General (launcher.cpp : 439) Closing gaps in paths | |
| 1336 [spades] 0:00:01.297 119M / 2G INFO General (launcher.cpp : 467) Gap closing completed | |
| 1337 [spades] 0:00:01.297 119M / 2G INFO General (launcher.cpp : 296) Traversing tandem repeats | |
| 1338 [spades] 0:00:01.297 119M / 2G INFO General (launcher.cpp : 306) Traversed 0 loops | |
| 1339 [spades] 0:00:01.297 119M / 2G INFO General (launcher.cpp : 244) Finalizing paths | |
| 1340 [spades] 0:00:01.297 119M / 2G INFO General (launcher.cpp : 246) Deduplicating paths | |
| 1341 [spades] 0:00:01.298 119M / 2G INFO General (launcher.cpp : 250) Paths deduplicated | |
| 1342 [spades] 0:00:01.298 119M / 2G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps | |
| 1343 [spades] 0:00:01.298 119M / 2G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths | |
| 1344 [spades] 0:00:01.298 119M / 2G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps | |
| 1345 [spades] 0:00:01.298 119M / 2G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps | |
| 1346 [spades] 0:00:01.298 119M / 2G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps | |
| 1347 [spades] 0:00:01.299 119M / 2G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths | |
| 1348 [spades] 0:00:01.299 119M / 2G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths | |
| 1349 [spades] 0:00:01.299 119M / 2G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed | |
| 1350 [spades] 0:00:01.299 119M / 2G INFO General (launcher.cpp : 267) Paths finalized | |
| 1351 [spades] 0:00:01.299 119M / 2G INFO General (launcher.cpp : 596) ExSPAnder repeat resolving tool finished | |
| 1352 [spades] 0:00:01.299 119M / 2G INFO StageManager (stage.cpp : 166) STAGE == Contig Output | |
| 1353 [spades] 0:00:01.300 119M / 2G INFO General (contig_output.hpp : 21) Outputting contigs to /home/piemari/shovill_bam/spades/K111/before_rr.fasta | |
| 1354 [spades] 0:00:01.302 119M / 2G INFO General (contig_output_stage.cpp : 146) Writing GFA graph to /home/piemari/shovill_bam/spades/K111/assembly_graph_with_scaffolds.gfa | |
| 1355 [spades] 0:00:01.302 119M / 2G INFO General (contig_output_stage.cpp : 160) Outputting FastG graph to /home/piemari/shovill_bam/spades/K111/assembly_graph.fastg | |
| 1356 [spades] 0:00:01.304 119M / 2G INFO General (contig_output_stage.cpp : 190) Breaking scaffolds | |
| 1357 [spades] 0:00:01.304 119M / 2G INFO General (contig_output_stage.cpp : 95) Outputting contigs to /home/piemari/shovill_bam/spades/K111/final_contigs.fasta | |
| 1358 [spades] 0:00:01.306 119M / 2G INFO General (contig_output_stage.cpp : 101) Outputting FastG paths to /home/piemari/shovill_bam/spades/K111/final_contigs.paths | |
| 1359 [spades] 0:00:01.307 119M / 2G INFO General (contig_output_stage.cpp : 95) Outputting contigs to /home/piemari/shovill_bam/spades/K111/scaffolds.fasta | |
| 1360 [spades] 0:00:01.308 119M / 2G INFO General (contig_output_stage.cpp : 101) Outputting FastG paths to /home/piemari/shovill_bam/spades/K111/scaffolds.paths | |
| 1361 [spades] 0:00:01.310 119M / 2G INFO General (contig_output_stage.cpp : 108) Populating GFA with scaffold paths | |
| 1362 [spades] 0:00:01.312 119M / 2G INFO General (pipeline.cpp : 259) SPAdes finished | |
| 1363 [spades] 0:00:01.313 116M / 2G INFO General (main.cpp : 107) Assembling time: 0 hours 0 minutes 1 seconds | |
| 1364 [spades] | |
| 1365 [spades] ===== K111 finished. | |
| 1366 [spades] | |
| 1367 [spades] | |
| 1368 [spades] ===== Copy files started. | |
| 1369 [spades] | |
| 1370 [spades] | |
| 1371 [spades] == Running: /home/piemari/apps/conda/envs/metaphlan/bin/python /home/piemari/apps/conda/envs/metaphlan/share/spades/spades_pipeline/scripts/copy_files.py /home/piemari/shovill_bam/spades/K111/before_rr.fasta /home/piemari/shovill_bam/spades/before_rr.fasta /home/piemari/shovill_bam/spades/K111/assembly_graph_after_simplification.gfa /home/piemari/shovill_bam/spades/assembly_graph_after_simplification.gfa /home/piemari/shovill_bam/spades/K111/final_contigs.fasta /home/piemari/shovill_bam/spades/contigs.fasta /home/piemari/shovill_bam/spades/K111/first_pe_contigs.fasta /home/piemari/shovill_bam/spades/first_pe_contigs.fasta /home/piemari/shovill_bam/spades/K111/strain_graph.gfa /home/piemari/shovill_bam/spades/strain_graph.gfa /home/piemari/shovill_bam/spades/K111/scaffolds.fasta /home/piemari/shovill_bam/spades/scaffolds.fasta /home/piemari/shovill_bam/spades/K111/scaffolds.paths /home/piemari/shovill_bam/spades/scaffolds.paths /home/piemari/shovill_bam/spades/K111/assembly_graph_with_scaffolds.gfa /home/piemari/shovill_bam/spades/assembly_graph_with_scaffolds.gfa /home/piemari/shovill_bam/spades/K111/assembly_graph.fastg /home/piemari/shovill_bam/spades/assembly_graph.fastg /home/piemari/shovill_bam/spades/K111/final_contigs.paths /home/piemari/shovill_bam/spades/contigs.paths | |
| 1372 [spades] | |
| 1373 [spades] | |
| 1374 [spades] ===== Copy files finished. | |
| 1375 [spades] | |
| 1376 [spades] | |
| 1377 [spades] ===== Assembling finished. | |
| 1378 [spades] | |
| 1379 [spades] | |
| 1380 [spades] ===== Breaking scaffolds started. | |
| 1381 [spades] | |
| 1382 [spades] | |
| 1383 [spades] == Running: /home/piemari/apps/conda/envs/metaphlan/bin/python /home/piemari/apps/conda/envs/metaphlan/share/spades/spades_pipeline/scripts/breaking_scaffolds_script.py --result_scaffolds_filename /home/piemari/shovill_bam/spades/scaffolds.fasta --misc_dir /home/piemari/shovill_bam/spades/misc --threshold_for_breaking_scaffolds 3 | |
| 1384 [spades] | |
| 1385 [spades] | |
| 1386 [spades] ===== Breaking scaffolds finished. | |
| 1387 [spades] | |
| 1388 [spades] | |
| 1389 [spades] ===== Terminate started. | |
| 1390 [spades] | |
| 1391 [spades] | |
| 1392 [spades] ===== Terminate finished. | |
| 1393 [spades] | |
| 1394 [spades] * Assembled contigs are in /home/piemari/shovill_bam/spades/contigs.fasta | |
| 1395 [spades] * Assembled scaffolds are in /home/piemari/shovill_bam/spades/scaffolds.fasta | |
| 1396 [spades] * Paths in the assembly graph corresponding to the contigs are in /home/piemari/shovill_bam/spades/contigs.paths | |
| 1397 [spades] * Paths in the assembly graph corresponding to the scaffolds are in /home/piemari/shovill_bam/spades/scaffolds.paths | |
| 1398 [spades] * Assembly graph is in /home/piemari/shovill_bam/spades/assembly_graph.fastg | |
| 1399 [spades] * Assembly graph in GFA format is in /home/piemari/shovill_bam/spades/assembly_graph_with_scaffolds.gfa | |
| 1400 [spades] | |
| 1401 [spades] ======= SPAdes pipeline finished. | |
| 1402 [spades] | |
| 1403 [spades] SPAdes log can be found here: /home/piemari/shovill_bam/spades/spades.log | |
| 1404 [spades] | |
| 1405 [spades] Thank you for using SPAdes! | |
| 1406 [shovill] Checking for assembly errors in spades.fasta | |
| 1407 [shovill] Running: bwa index spades.fasta 2>&1 | sed 's/^/[bwa-index] /' | tee -a shovill.log | |
| 1408 [bwa-index] [bwa_index] Pack FASTA... 0.00 sec | |
| 1409 [bwa-index] [bwa_index] Construct BWT for the packed sequence... | |
| 1410 [bwa-index] [bwa_index] 0.00 seconds elapse. | |
| 1411 [bwa-index] [bwa_index] Update BWT... 0.00 sec | |
| 1412 [bwa-index] [bwa_index] Pack forward-only FASTA... 0.00 sec | |
| 1413 [bwa-index] [bwa_index] Construct SA from BWT and Occ... 0.00 sec | |
| 1414 [bwa-index] [main] Version: 0.7.17-r1188 | |
| 1415 [bwa-index] [main] CMD: bwa index spades.fasta | |
| 1416 [bwa-index] [main] Real time: 0.012 sec; CPU: 0.004 sec | |
| 1417 [shovill] Running: samtools faidx spades.fasta 2>&1 | sed 's/^/[faidx] /' | tee -a shovill.log | |
| 1418 [shovill] Running: (bwa mem -v 3 -x intractg -t 8 spades.fasta R1.fq.gz R2.fq.gz | samclip --ref spades.fasta.fai | samtools sort --threads 2 -m 1024m --reference spades.fasta -T /tmp -o shovill.bam) 2>&1 | sed 's/^/[bwa+samtools-sort] /' | tee -a shovill.log | |
| 1419 [bwa+samtools-sort] [M::bwa_idx_load_from_disk] read 0 ALT contigs | |
| 1420 [bwa+samtools-sort] [M::process] read 820 sequences (123000 bp)... | |
| 1421 [bwa+samtools-sort] [M::mem_pestat] # candidate unique pairs for (FF, FR, RF, RR): (0, 410, 0, 0) | |
| 1422 [bwa+samtools-sort] [M::mem_pestat] skip orientation FF as there are not enough pairs | |
| 1423 [bwa+samtools-sort] [M::mem_pestat] analyzing insert size distribution for orientation FR... | |
| 1424 [bwa+samtools-sort] [M::mem_pestat] (25, 50, 75) percentile: (163, 197, 230) | |
| 1425 [bwa+samtools-sort] [M::mem_pestat] low and high boundaries for computing mean and std.dev: (29, 364) | |
| 1426 [bwa+samtools-sort] [M::mem_pestat] mean and std.dev: (200.81, 42.23) | |
| 1427 [bwa+samtools-sort] [M::mem_pestat] low and high boundaries for proper pairs: (1, 431) | |
| 1428 [bwa+samtools-sort] [M::mem_pestat] skip orientation RF as there are not enough pairs | |
| 1429 [bwa+samtools-sort] [M::mem_pestat] skip orientation RR as there are not enough pairs | |
| 1430 [bwa+samtools-sort] [M::mem_process_seqs] Processed 820 reads in 0.101 CPU sec, 0.021 real sec | |
| 1431 [bwa+samtools-sort] [samclip] samclip 0.4.0 by Torsten Seemann (@torstenseemann) | |
| 1432 [bwa+samtools-sort] [samclip] Loading: spades.fasta.fai | |
| 1433 [bwa+samtools-sort] [samclip] Found 1 sequences in spades.fasta.fai | |
| 1434 [bwa+samtools-sort] [main] Version: 0.7.17-r1188 | |
| 1435 [bwa+samtools-sort] [main] CMD: bwa mem -v 3 -x intractg -t 8 spades.fasta R1.fq.gz R2.fq.gz | |
| 1436 [bwa+samtools-sort] [main] Real time: 0.053 sec; CPU: 0.107 sec | |
| 1437 [bwa+samtools-sort] [samclip] Total SAM records 820, removed 63, allowed 123, passed 757 | |
| 1438 [bwa+samtools-sort] [samclip] Header contained 2 lines | |
| 1439 [bwa+samtools-sort] [samclip] Done. | |
| 1440 [bwa+samtools-sort] [bam_sort_core] merging from 0 files and 2 in-memory blocks... | |
| 1441 [shovill] Running: samtools index shovill.bam 2>&1 | sed 's/^/[samtools-index] /' | tee -a shovill.log | |
| 1442 [shovill] Correcting errors in spades.fasta | |
| 1443 [shovill] Running: pilon --genome spades.fasta --frags shovill.bam --minmq 60 --minqual 3 --fix bases --output pilon --threads 8 --changes --mindepth 0.25 2>&1 | sed 's/^/[pilon] /' | tee -a shovill.log | |
| 1444 [pilon] Picked up _JAVA_OPTIONS: -Xmx4g | |
| 1445 [pilon] Pilon version 1.24 Thu Jan 28 13:00:45 2021 -0500 | |
| 1446 [pilon] --threads argument no longer supported; ignoring! | |
| 1447 [pilon] Genome: spades.fasta | |
| 1448 [pilon] Fixing snps, indels | |
| 1449 [pilon] Input genome size: 1251 | |
| 1450 [pilon] Processing NODE_1_length_1251_cov_25.164912:1-1251 | |
| 1451 [pilon] frags shovill.bam: coverage 79 | |
| 1452 [pilon] Total Reads: 757, Coverage: 79, minDepth: 20 | |
| 1453 [pilon] Confirmed 1152 of 1251 bases (92,09%) | |
| 1454 [pilon] Corrected 0 snps; 0 ambiguous bases; corrected 0 small insertions totaling 0 bases, 0 small deletions totaling 0 bases | |
| 1455 [pilon] NODE_1_length_1251_cov_25.164912:1-1251 log: | |
| 1456 [pilon] Finished processing NODE_1_length_1251_cov_25.164912:1-1251 | |
| 1457 [pilon] Writing NODE_1_length_1251_cov_25.164912:1-1251 changes to pilon.changes | |
| 1458 [pilon] Writing updated NODE_1_length_1251_cov_25.164912_pilon to pilon.fasta | |
| 1459 [pilon] Mean frags coverage: 79 | |
| 1460 [pilon] Mean total coverage: 79 | |
| 1461 [shovill] Repaired 0 contigs from spades.fasta at 0 positions. | |
| 1462 [shovill] Assembly is 1251, estimated genome size was 1188 (+5.30%) | |
| 1463 [shovill] Using genome graph file 'spades/assembly_graph_with_scaffolds.gfa' => 'contigs.gfa' | |
| 1464 [shovill] Walltime used: 0 min 10 sec | |
| 1465 [shovill] Results in: /home/piemari/shovill_bam | |
| 1466 [shovill] Final assembly graph: /home/piemari/shovill_bam/contigs.gfa | |
| 1467 [shovill] Final assembly contigs: /home/piemari/shovill_bam/contigs.fa | |
| 1468 [shovill] It contains 1 (min=75) contigs totalling 1251 bp. | |
| 1469 [shovill] Have a suggestion for shovill? Tell me at https://github.com/tseemann/shovill/issues | |
| 1470 [shovill] Done. |