Building DAG of jobs... Using shell: /bin/bash Provided cores: 1 (use --cores to define parallelism) Rules claiming more threads will be scaled down. Select jobs to execute... [Wed Apr 19 10:55:45 2023] rule assemble: input: 00_reads/SRR341563_trimmed.done output: SRR341563.assembled jobid: 0 wildcards: sample=SRR341563 resources: mem_mb=1000, disk_mb=1000, tmpdir=/tmp == Warning == No assembly mode was specified! If you intend to assemble high-coverage multi-cell/isolate data, use '--isolate' option. Command line: /opt/software/SPAdes/3.15.3-GCC-11.2.0/bin/spades.py -1 /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_1P.fastq.gz -2 /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_2P.fastq.gz -s /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_U.fastq -o /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome -t 4 System information: SPAdes version: 3.15.3 Python version: 3.9.6 OS: Linux-3.10.0-1160.88.1.el7.x86_64-x86_64-with-glibc2.17 Output dir: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome Mode: read error correction and assembling Debug mode is turned OFF Dataset parameters: Standard mode For multi-cell/isolate data we recommend to use '--isolate' option; for single-cell MDA data use '--sc'; for metagenomic data use '--meta'; for RNA-Seq use '--rna'. Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_1P.fastq.gz'] right reads: ['/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_2P.fastq.gz'] interlaced reads: not specified single reads: ['/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_U.fastq'] merged reads: not specified Read error correction parameters: Iterations: 1 PHRED offset will be auto-detected Corrected reads will be compressed Assembly parameters: k: automatic selection based on read length Repeat resolution is enabled Mismatch careful mode is turned OFF MismatchCorrector will be SKIPPED Coverage cutoff is turned OFF Other parameters: Dir for temp files: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/tmp Threads: 4 Memory limit (in Gb): 125 ======= SPAdes pipeline started. Log can be found here: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/spades.log /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_1P.fastq.gz: max reads length: 101 /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_2P.fastq.gz: max reads length: 101 /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_U.fastq: max reads length: 101 Reads length: 101 ===== Before start started. ===== Read error correction started. ===== Read error correction started. == Running: /opt/software/SPAdes/3.15.3-GCC-11.2.0/bin/spades-hammer /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/configs/config.info 0:00:00.000 1M / 11M INFO General (main.cpp : 75) Starting BayesHammer, built from N/A, git revision N/A 0:00:00.000 1M / 11M INFO General (main.cpp : 76) Loading config from /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/configs/config.info 0:00:00.005 1M / 11M INFO General (main.cpp : 78) Maximum # of threads to use (adjusted due to OMP capabilities): 1 0:00:00.005 1M / 11M INFO General (memory_limit.cpp : 48) Memory limit set to 125 Gb 0:00:00.005 1M / 11M INFO General (main.cpp : 86) Trying to determine PHRED offset 0:00:00.008 1M / 11M INFO General (main.cpp : 92) Determined value is 33 0:00:00.008 1M / 11M INFO General (hammer_tools.cpp : 38) Hamming graph threshold tau=1, k=21, subkmer positions = [ 0 10 ] 0:00:00.008 1M / 11M INFO General (main.cpp : 113) Size of aux. kmer data 24 bytes === ITERATION 0 begins === 0:00:00.705 1M / 11M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 16 files using 1 threads. This might take a while. 0:00:00.795 1M / 11M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.795 1M / 11M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 41.6666 Gb 0:00:00.795 1M / 11M INFO General (kmer_splitter.hpp : 101) Using cell size of 4194304 0:00:00.801 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 97) Processing /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_1P.fastq.gz 0:00:13.262 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 454528 reads 0:00:23.024 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 907745 reads 0:00:32.866 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 1361173 reads 0:00:42.631 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 1815605 reads 0:00:52.576 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 2266901 reads 0:01:02.204 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 2720833 reads 0:01:11.890 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 3173691 reads 0:01:17.726 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 97) Processing /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_2P.fastq.gz 0:01:36.784 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 107) Processed 4304422 reads 0:02:33.525 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 97) Processing /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_U.fastq 0:02:43.515 577M / 577M INFO K-mer Splitting (kmer_data.cpp : 112) Total 7339213 reads processed 0:02:43.515 1M / 571M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:02:48.646 1M / 571M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 18507342 kmers in total. 0:02:48.686 1M / 571M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:02:50.643 15M / 571M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 18507342 kmers, 13378952 bytes occupied (5.7832 bits per kmer). 0:02:50.643 15M / 571M INFO K-mer Counting (kmer_data.cpp : 354) Arranging kmers in hash map order 0:02:51.871 303M / 571M INFO General (main.cpp : 148) Clustering Hamming graph. 0:03:43.851 303M / 571M INFO General (main.cpp : 155) Extracting clusters: 0:03:43.851 303M / 571M INFO General (concurrent_dsu.cpp : 18) Connecting to root 0:03:44.039 303M / 571M INFO General (concurrent_dsu.cpp : 34) Calculating counts 0:03:45.322 576M / 745M INFO General (concurrent_dsu.cpp : 63) Writing down entries 0:03:48.538 303M / 889M INFO General (main.cpp : 167) Clustering done. Total clusters: 11604760 0:03:48.538 159M / 889M INFO K-mer Counting (kmer_data.cpp : 371) Collecting K-mer information, this takes a while. 0:03:48.653 583M / 889M INFO K-mer Counting (kmer_data.cpp : 377) Processing /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_1P.fastq.gz 0:05:07.170 583M / 889M INFO K-mer Counting (kmer_data.cpp : 377) Processing /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_2P.fastq.gz 0:06:27.116 583M / 889M INFO K-mer Counting (kmer_data.cpp : 377) Processing /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_U.fastq 0:06:38.082 583M / 889M INFO K-mer Counting (kmer_data.cpp : 384) Collection done, postprocessing. 0:06:38.121 583M / 889M INFO K-mer Counting (kmer_data.cpp : 397) There are 18507342 kmers in total. Among them 7826172 (42.2869%) are singletons. 0:06:38.121 583M / 889M INFO General (main.cpp : 173) Subclustering Hamming graph 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 650) Subclustering done. Total 105 non-read kmers were generated. 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 651) Subclustering statistics: 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 652) Total singleton hamming clusters: 6729144. Among them 5867774 (87.1994%) are good 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 653) Total singleton subclusters: 106927. Among them 106629 (99.7213%) are good 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 654) Total non-singleton subcluster centers: 4891891. Among them 4287714 (87.6494%) are good 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 655) Average size of non-trivial subcluster: 2.40772 kmers 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 656) Average number of sub-clusters per non-singleton cluster: 1.02527 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 657) Total solid k-mers: 10262117 0:06:53.195 583M / 889M INFO Hamming Subclustering (kmer_cluster.cpp : 658) Substitution probabilities: [4,4]((0.958967,0.00852681,0.0203803,0.0121258),(0.023903,0.944451,0.00834587,0.0233005),(0.023242,0.0082776,0.944535,0.0239451),(0.0120752,0.0203251,0.00848663,0.959113)) 0:06:53.254 583M / 889M INFO General (main.cpp : 178) Finished clustering. 0:06:53.254 583M / 889M INFO General (main.cpp : 197) Starting solid k-mers expansion in 1 threads. 0:07:30.497 583M / 889M INFO General (main.cpp : 218) Solid k-mers iteration 0 produced 185623 new k-mers. 0:08:07.706 583M / 889M INFO General (main.cpp : 218) Solid k-mers iteration 1 produced 6636 new k-mers. 0:08:44.751 583M / 889M INFO General (main.cpp : 218) Solid k-mers iteration 2 produced 120 new k-mers. 0:09:22.008 583M / 889M INFO General (main.cpp : 218) Solid k-mers iteration 3 produced 0 new k-mers. 0:09:22.008 583M / 889M INFO General (main.cpp : 222) Solid k-mers finalized 0:09:22.008 583M / 889M INFO General (hammer_tools.cpp : 222) Starting read correction in 1 threads. 0:09:22.008 583M / 889M INFO General (hammer_tools.cpp : 235) Correcting pair of reads: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_1P.fastq.gz and /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_2P.fastq.gz 0:09:22.701 655M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 0 of 100000 reads. 0:09:23.388 661M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 0 0:09:23.760 661M / 889M INFO General (hammer_tools.cpp : 187) Written batch 0 0:09:24.082 669M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 1 of 100000 reads. 0:09:24.799 669M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 1 0:09:25.177 669M / 889M INFO General (hammer_tools.cpp : 187) Written batch 1 0:09:25.489 670M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 2 of 100000 reads. 0:09:26.195 670M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 2 0:09:26.575 670M / 889M INFO General (hammer_tools.cpp : 187) Written batch 2 0:09:26.887 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 3 of 100000 reads. 0:09:27.581 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 3 0:09:27.960 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 3 0:09:28.275 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 4 of 100000 reads. 0:09:28.998 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 4 0:09:29.376 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 4 0:09:29.687 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 5 of 100000 reads. 0:09:30.403 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 5 0:09:30.781 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 5 0:09:31.097 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 6 of 100000 reads. 0:09:31.802 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 6 0:09:32.181 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 6 0:09:32.496 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 7 of 100000 reads. 0:09:33.237 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 7 0:09:33.624 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 7 0:09:33.932 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 8 of 100000 reads. 0:09:34.651 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 8 0:09:35.099 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 8 0:09:35.411 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 9 of 100000 reads. 0:09:36.163 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 9 0:09:36.613 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 9 0:09:36.914 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 10 of 100000 reads. 0:09:37.651 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 10 0:09:38.103 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 10 0:09:38.416 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 11 of 100000 reads. 0:09:39.150 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 11 0:09:39.603 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 11 0:09:39.914 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 12 of 100000 reads. 0:09:40.657 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 12 0:09:41.020 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 12 0:09:41.332 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 13 of 100000 reads. 0:09:42.067 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 13 0:09:42.430 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 13 0:09:42.741 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 14 of 100000 reads. 0:09:43.473 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 14 0:09:43.834 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 14 0:09:44.152 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 15 of 100000 reads. 0:09:44.887 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 15 0:09:45.251 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 15 0:09:45.561 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 16 of 100000 reads. 0:09:46.264 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 16 0:09:46.625 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 16 0:09:46.937 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 17 of 100000 reads. 0:09:47.643 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 17 0:09:48.005 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 17 0:09:48.317 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 18 of 100000 reads. 0:09:49.015 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 18 0:09:49.377 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 18 0:09:49.692 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 19 of 100000 reads. 0:09:50.392 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 19 0:09:50.756 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 19 0:09:51.075 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 20 of 100000 reads. 0:09:51.799 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 20 0:09:52.165 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 20 0:09:52.476 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 21 of 100000 reads. 0:09:53.168 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 21 0:09:53.532 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 21 0:09:53.843 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 22 of 100000 reads. 0:09:54.560 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 22 0:09:54.924 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 22 0:09:55.235 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 23 of 100000 reads. 0:09:55.924 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 23 0:09:56.292 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 23 0:09:56.604 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 24 of 100000 reads. 0:09:57.302 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 24 0:09:57.666 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 24 0:09:57.973 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 25 of 100000 reads. 0:09:58.659 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 25 0:09:59.021 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 25 0:09:59.340 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 26 of 100000 reads. 0:10:00.057 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 26 0:10:00.421 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 26 0:10:00.731 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 27 of 100000 reads. 0:10:01.449 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 27 0:10:01.812 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 27 0:10:02.131 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 28 of 100000 reads. 0:10:02.819 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 28 0:10:03.189 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 28 0:10:03.501 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 29 of 100000 reads. 0:10:04.217 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 29 0:10:04.581 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 29 0:10:04.892 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 30 of 100000 reads. 0:10:05.587 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 30 0:10:05.952 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 30 0:10:06.264 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 31 of 100000 reads. 0:10:06.975 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 31 0:10:07.340 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 31 0:10:07.712 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 32 of 100000 reads. 0:10:10.373 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 32 0:10:10.739 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 32 0:10:11.106 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 33 of 100000 reads. 0:10:13.801 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 33 0:10:14.170 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 33 0:10:14.315 671M / 889M INFO General (hammer_tools.cpp : 170) Prepared batch 34 of 37650 reads. 0:10:15.314 671M / 889M INFO General (hammer_tools.cpp : 177) Processed batch 34 0:10:15.451 671M / 889M INFO General (hammer_tools.cpp : 187) Written batch 34 0:10:15.473 583M / 889M INFO General (hammer_tools.cpp : 266) Correcting single reads: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/00_reads/SRR341563_trimmed_U.fastq 0:10:15.688 617M / 889M INFO General (hammer_tools.cpp : 129) Prepared batch 0 of 100000 reads. 0:10:16.428 620M / 889M INFO General (hammer_tools.cpp : 134) Processed batch 0 0:10:16.593 620M / 889M INFO General (hammer_tools.cpp : 138) Written batch 0 0:10:16.670 625M / 889M INFO General (hammer_tools.cpp : 129) Prepared batch 1 of 100000 reads. 0:10:17.420 625M / 889M INFO General (hammer_tools.cpp : 134) Processed batch 1 0:10:17.592 625M / 889M INFO General (hammer_tools.cpp : 138) Written batch 1 0:10:17.668 627M / 889M INFO General (hammer_tools.cpp : 129) Prepared batch 2 of 100000 reads. 0:10:18.390 627M / 889M INFO General (hammer_tools.cpp : 134) Processed batch 2 0:10:18.560 627M / 889M INFO General (hammer_tools.cpp : 138) Written batch 2 0:10:18.634 628M / 889M INFO General (hammer_tools.cpp : 129) Prepared batch 3 of 100000 reads. 0:10:19.548 628M / 889M INFO General (hammer_tools.cpp : 134) Processed batch 3 0:10:19.716 628M / 889M INFO General (hammer_tools.cpp : 138) Written batch 3 0:10:19.765 628M / 889M INFO General (hammer_tools.cpp : 129) Prepared batch 4 of 63913 reads. 0:10:20.348 628M / 889M INFO General (hammer_tools.cpp : 134) Processed batch 4 0:10:20.455 628M / 889M INFO General (hammer_tools.cpp : 138) Written batch 4 0:10:20.465 583M / 889M INFO General (hammer_tools.cpp : 276) Correction done. Changed 191712 bases in 188195 reads. 0:10:20.465 583M / 889M INFO General (hammer_tools.cpp : 277) Failed to correct 0 bases out of 693677328. 0:10:20.466 1M / 889M INFO General (main.cpp : 255) Saving corrected dataset description to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/corrected.yaml 0:10:20.620 1M / 889M INFO General (main.cpp : 262) All done. Exiting. ===== Read error correction finished. ===== corrected reads compression started. == Running: /opt/software/Python/3.9.6-GCCcore-11.2.0/bin/python /opt/software/SPAdes/3.15.3-GCC-11.2.0/share/spades/spades_pipeline/scripts/compress_all.py --input_file /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/corrected.yaml --ext_python_modules_home /opt/software/SPAdes/3.15.3-GCC-11.2.0/share/spades --max_threads 4 --output_dir /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected --gzip_output == Compressing corrected reads (with pigz) == Files to compress: ['/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/SRR341563_trimmed_1P.fastq.00.0_0.cor.fastq', '/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/SRR341563_trimmed_2P.fastq.00.0_0.cor.fastq', '/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/SRR341563_trimmed__unpaired.00.0_0.cor.fastq', '/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/SRR341563_trimmed_U.00.0_1.cor.fastq'] == Files compression is finished == Dataset yaml file is updated ===== corrected reads compression finished. ===== Read error correction finished. ===== Assembling started. ===== K21 started. == Running: /opt/software/SPAdes/3.15.3-GCC-11.2.0/bin/spades-core /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K21/configs/config.info 0:00:00.000 1M / 11M INFO General (main.cpp : 99) Loaded config from /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K21/configs/config.info 0:00:00.000 1M / 11M INFO General (memory_limit.cpp : 48) Memory limit set to 125 Gb 0:00:00.000 1M / 11M INFO General (main.cpp : 107) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 1M / 11M INFO General (main.cpp : 108) Maximum k-mer length: 128 0:00:00.000 1M / 11M INFO General (main.cpp : 109) Assembling dataset (/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/dataset.info) with K=21 0:00:00.000 1M / 11M INFO General (main.cpp : 110) Maximum # of threads to use (adjusted due to OMP capabilities): 1 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 212) SPAdes started 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 225) Starting from stage: read_conversion 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 231) Two-step repeat resolution disabled 0:00:00.000 1M / 11M INFO GraphCore (graph_core.hpp : 672) Graph created, vertex min_id: 3, edge min_id: 3 0:00:00.000 1M / 11M INFO GraphCore (graph_core.hpp : 673) Vertex size: 48, edge size: 40 0:00:00.000 1M / 11M INFO General (edge_index.hpp : 113) Size of edge index entries: 12/8 0:00:00.000 1M / 11M INFO StageManager (stage.cpp : 185) STAGE == Binary Read Conversion (id: read_conversion) 0:00:00.060 1M / 11M INFO General (read_converter.cpp : 72) Converting reads to binary format for library #0 (takes a while) 0:00:00.060 1M / 11M INFO General (read_converter.cpp : 73) Converting paired reads 0:00:00.387 26M / 26M INFO General (binary_converter.cpp : 96) 16384 reads processed 0:00:00.526 29M / 29M INFO General (binary_converter.cpp : 96) 32768 reads processed 0:00:00.884 26M / 32M INFO General (binary_converter.cpp : 96) 65536 reads processed 0:00:01.519 29M / 40M INFO General (binary_converter.cpp : 96) 131072 reads processed 0:00:02.870 25M / 40M INFO General (binary_converter.cpp : 96) 262144 reads processed 0:00:05.458 28M / 40M INFO General (binary_converter.cpp : 96) 524288 reads processed 0:00:10.621 33M / 40M INFO General (binary_converter.cpp : 96) 1048576 reads processed 0:00:21.092 32M / 40M INFO General (binary_converter.cpp : 96) 2097152 reads processed 0:00:34.832 23M / 40M INFO General (binary_converter.cpp : 111) 3437338 reads written 0:00:34.832 1M / 40M INFO General (read_converter.cpp : 86) Converting single reads 0:00:35.212 12M / 40M INFO General (binary_converter.cpp : 96) 16384 reads processed 0:00:35.276 14M / 40M INFO General (binary_converter.cpp : 96) 32768 reads processed 0:00:35.448 12M / 40M INFO General (binary_converter.cpp : 96) 65536 reads processed 0:00:35.756 14M / 40M INFO General (binary_converter.cpp : 96) 131072 reads processed 0:00:36.410 12M / 40M INFO General (binary_converter.cpp : 96) 262144 reads processed 0:00:37.417 11M / 40M INFO General (binary_converter.cpp : 111) 464036 reads written 0:00:37.418 1M / 40M INFO General (read_converter.cpp : 92) Converting merged reads 0:00:37.641 11M / 40M INFO General (binary_converter.cpp : 111) 0 reads written 0:00:37.650 1M / 40M INFO StageManager (stage.cpp : 185) STAGE == de Bruijn graph construction (id: construction) 0:00:37.883 1M / 40M INFO General (construction.cpp : 153) Max read length 101 0:00:37.883 1M / 40M INFO General (construction.cpp : 159) Average read length 94.5203 0:00:37.883 1M / 40M INFO General (stage.cpp : 117) PROCEDURE == k+1-mer counting (id: construction:kpomer_counting) 0:00:37.883 1M / 40M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 10 files using 1 threads. This might take a while. 0:00:37.962 1M / 40M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:37.962 1M / 40M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 41.6666 Gb 0:00:37.962 1M / 40M INFO General (kmer_splitter.hpp : 101) Using cell size of 6710886 0:00:54.254 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 1950985 reads 0:01:07.257 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 3755261 reads 0:01:20.318 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 5549219 reads 0:01:33.322 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 7345083 reads 0:01:46.262 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 9142684 reads 0:01:59.245 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 10944095 reads 0:02:12.008 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 12741219 reads 0:02:25.454 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 14527337 reads 0:02:26.732 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 14677424 reads 0:02:26.732 1M / 580M INFO General (kmer_splitters.hpp : 131) Used 14677424 reads 0:02:26.733 1M / 580M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:02:28.883 1M / 580M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 6191328 kmers in total. 0:02:28.883 1M / 580M INFO General (stage.cpp : 117) PROCEDURE == Extension index construction (id: construction:extension_index_construction) 0:02:28.895 1M / 580M INFO K-mer Index Building (kmer_index_builder.hpp : 438) Building kmer index 0:02:28.895 1M / 580M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 10 files using 1 threads. This might take a while. 0:02:28.979 1M / 580M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:02:28.979 1M / 580M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 41.6666 Gb 0:02:28.979 1M / 580M INFO General (kmer_splitter.hpp : 101) Using cell size of 6710886 0:02:32.843 601M / 601M INFO General (kmer_splitters.hpp : 194) Processed 6191328 kmers 0:02:32.843 601M / 601M INFO General (kmer_splitters.hpp : 199) Used 6191328 kmers. 0:02:32.843 1M / 580M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:02:34.684 1M / 580M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 6159480 kmers in total. 0:02:34.684 1M / 580M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:02:35.368 5M / 580M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 6159480 kmers, 4456176 bytes occupied (5.78773 bits per kmer). 0:02:35.368 5M / 580M INFO General (kmer_index_builder.hpp : 169) Merging final buckets. 0:02:35.687 11M / 580M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 100) Building k-mer extensions from k+1-mers 0:02:36.821 11M / 580M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 105) Building k-mer extensions from k+1-mers finished. 0:02:36.822 11M / 580M INFO General (stage.cpp : 117) PROCEDURE == Early tip clipping (id: construction:early_tip_clipper) 0:02:36.822 11M / 580M INFO General (construction.cpp : 301) Early tip clipper length bound set as (RL - K) 0:02:36.822 11M / 580M INFO Early tip clipping (early_simplification.hpp : 47) Early tip clipping 0:02:38.094 21M / 580M INFO Early tip clipping (early_simplification.hpp : 82) #tipped junctions: 88947 0:02:38.113 21M / 580M INFO Early tip clipping (early_simplification.hpp : 93) Clipped tips: 89168 0:02:38.114 11M / 580M INFO Early tip clipping (early_simplification.hpp : 49) 435036 22-mers were removed by early tip clipper 0:02:38.114 11M / 580M INFO General (stage.cpp : 117) PROCEDURE == Condensing graph (id: construction:graph_condensing) 0:02:38.130 11M / 580M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths 0:02:39.667 16M / 580M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 95724 sequences extracted 0:02:40.511 16M / 580M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops 0:02:40.891 16M / 580M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 2 loops collected 0:02:40.896 16M / 580M INFO General (debruijn_graph_constructor: 487) Total 191452 edges to create 0:02:40.896 24M / 580M INFO General (debruijn_graph_constructor: 489) Collecting link records 0:02:40.929 27M / 580M INFO General (debruijn_graph_constructor: 491) Ordering link records 0:02:40.942 27M / 580M INFO General (debruijn_graph_constructor: 493) Sorting done 0:02:40.943 27M / 580M INFO General (debruijn_graph_constructor: 503) Total 63878 vertices to create 0:02:40.943 33M / 580M INFO General (debruijn_graph_constructor: 506) Connecting the graph 0:02:40.956 28M / 580M INFO General (stage.cpp : 117) PROCEDURE == Filling coverage indices (PHM) (id: construction:coverage_filling_phm) 0:02:40.956 28M / 580M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:02:41.607 33M / 580M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 6191328 kmers, 4479112 bytes occupied (5.78759 bits per kmer). 0:02:41.611 57M / 580M INFO General (coverage_hash_map_builder.: 47) Collecting k-mer coverage information from reads, this takes a while. 0:03:10.995 57M / 580M INFO General (construction.cpp : 430) Filling coverage and flanking coverage from PHM 0:03:11.939 57M / 580M INFO General (coverage_filling.hpp : 82) Processed 191350 edges 0:03:12.226 18M / 580M INFO StageManager (stage.cpp : 185) STAGE == EC Threshold Finding (id: ec_threshold_finder) 0:03:12.226 18M / 580M INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 8 0:03:12.226 18M / 580M INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 101 0:03:12.226 18M / 580M INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 101. Coverage mad: 19.2738 0:03:12.226 18M / 580M INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:03:12.311 18M / 580M INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:03:12.534 18M / 580M INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:03:13.155 18M / 580M INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:03:15.001 18M / 580M INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:03:17.629 18M / 580M INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 98.901. Fitted coverage std. dev: 18.4968 0:03:17.632 18M / 580M INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.968508 0:03:17.632 18M / 580M INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 42 0:03:17.632 18M / 580M INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 42 0:03:17.632 18M / 580M INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 5176679 0:03:17.632 18M / 580M INFO General (genomic_info_filler.cpp : 55) Mean coverage was calculated as 98.901 0:03:17.632 18M / 580M INFO General (genomic_info_filler.cpp : 70) EC coverage threshold value was calculated as 42 0:03:17.632 18M / 580M INFO General (genomic_info_filler.cpp : 71) Trusted kmer low bound: 0 0:03:17.632 18M / 580M INFO StageManager (stage.cpp : 185) STAGE == Raw Simplification (id: raw_simplification) 0:03:17.632 18M / 580M INFO General (simplification.cpp : 127) PROCEDURE == Initial cleaning 0:03:17.632 18M / 580M INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:03:17.632 18M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Self conjugate edge remover 0:03:17.640 18M / 580M INFO Simplification (parallel_processing.hpp : 170) Self conjugate edge remover triggered 0 times 0:03:17.640 18M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Initial tip clipper 0:03:17.650 18M / 580M INFO Simplification (parallel_processing.hpp : 170) Initial tip clipper triggered 155 times 0:03:17.650 18M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Initial ec remover 0:03:17.853 18M / 580M INFO Simplification (parallel_processing.hpp : 170) Initial ec remover triggered 28903 times 0:03:17.854 18M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Initial isolated edge remover 0:03:17.856 18M / 580M INFO Simplification (parallel_processing.hpp : 170) Initial isolated edge remover triggered 548 times 0:03:17.856 16M / 580M INFO StageManager (stage.cpp : 185) STAGE == Simplification (id: simplification) 0:03:17.856 16M / 580M INFO General (simplification.cpp : 368) Graph simplification started 0:03:17.856 16M / 580M INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:03:17.856 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 1 0:03:17.856 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.867 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 615 times 0:03:17.867 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.892 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 2057 times 0:03:17.892 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.900 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 235 times 0:03:17.900 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 2 0:03:17.900 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.901 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.901 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.901 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 4 times 0:03:17.901 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 39 times 0:03:17.902 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 3 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 1 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 6 times 0:03:17.902 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 4 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 9 times 0:03:17.902 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 5 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 1 times 0:03:17.902 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 6 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:03:17.902 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 7 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 1 times 0:03:17.902 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 8 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:03:17.902 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 9 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.902 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 3 times 0:03:17.903 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 10 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 3 times 0:03:17.903 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 11 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.903 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.905 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 1 times 0:03:17.905 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:03:17.906 16M / 580M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 12 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:03:17.906 16M / 580M INFO StageManager (stage.cpp : 185) STAGE == Simplification Cleanup (id: simplification_cleanup) 0:03:17.906 16M / 580M INFO General (simplification.cpp : 176) PROCEDURE == Post simplification 0:03:17.906 16M / 580M INFO General (graph_simplification.hpp : 448) Disconnection of relatively low covered edges disabled 0:03:17.906 16M / 580M INFO General (graph_simplification.hpp : 485) Complex tip clipping disabled 0:03:17.906 16M / 580M INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:03:17.906 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.907 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.907 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.909 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.909 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:03:17.909 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:03:17.909 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:03:17.911 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:03:17.911 16M / 580M INFO General (simplification.cpp : 327) Disrupting self-conjugate edges 0:03:17.912 16M / 580M INFO Simplification (parallel_processing.hpp : 167) Running Removing isolated edges 0:03:17.912 16M / 580M INFO Simplification (parallel_processing.hpp : 170) Removing isolated edges triggered 13 times 0:03:17.912 16M / 580M INFO General (simplification.cpp : 491) Counting average coverage 0:03:17.912 16M / 580M INFO General (simplification.cpp : 497) Average coverage = 103.809 0:03:17.912 16M / 580M INFO StageManager (stage.cpp : 185) STAGE == Contig Output (id: contig_output) 0:03:18.192 16M / 580M INFO General (read_converter.cpp : 107) Outputting contigs to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K21/simplified_contigs 0:03:18.398 18M / 580M INFO General (binary_converter.cpp : 111) 3159 reads written 0:03:18.523 16M / 580M INFO General (pipeline.cpp : 287) SPAdes finished 0:03:18.524 1M / 580M INFO General (main.cpp : 136) Assembling time: 0 hours 3 minutes 18 seconds ===== K21 finished. ===== K33 started. == Running: /opt/software/SPAdes/3.15.3-GCC-11.2.0/bin/spades-core /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K33/configs/config.info 0:00:00.000 1M / 11M INFO General (main.cpp : 99) Loaded config from /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K33/configs/config.info 0:00:00.000 1M / 11M INFO General (memory_limit.cpp : 48) Memory limit set to 125 Gb 0:00:00.000 1M / 11M INFO General (main.cpp : 107) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 1M / 11M INFO General (main.cpp : 108) Maximum k-mer length: 128 0:00:00.000 1M / 11M INFO General (main.cpp : 109) Assembling dataset (/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/dataset.info) with K=33 0:00:00.000 1M / 11M INFO General (main.cpp : 110) Maximum # of threads to use (adjusted due to OMP capabilities): 1 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 212) SPAdes started 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 225) Starting from stage: read_conversion 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 231) Two-step repeat resolution disabled 0:00:00.000 1M / 11M INFO GraphCore (graph_core.hpp : 672) Graph created, vertex min_id: 3, edge min_id: 3 0:00:00.000 1M / 11M INFO GraphCore (graph_core.hpp : 673) Vertex size: 48, edge size: 40 0:00:00.000 1M / 11M INFO General (edge_index.hpp : 113) Size of edge index entries: 12/8 0:00:00.000 1M / 11M INFO StageManager (stage.cpp : 185) STAGE == Binary Read Conversion (id: read_conversion) 0:00:00.002 1M / 11M INFO General (read_converter.cpp : 53) Binary reads detected 0:00:00.002 1M / 11M INFO StageManager (stage.cpp : 185) STAGE == de Bruijn graph construction (id: construction) 0:00:00.002 1M / 11M INFO General (construction.cpp : 118) Contigs from previous K will be used: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K21/simplified_contigs 0:00:00.269 1M / 11M INFO General (construction.cpp : 153) Max read length 101 0:00:00.269 1M / 11M INFO General (construction.cpp : 159) Average read length 94.5203 0:00:00.269 1M / 11M INFO General (stage.cpp : 117) PROCEDURE == k+1-mer counting (id: construction:kpomer_counting) 0:00:00.269 1M / 11M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 10 files using 1 threads. This might take a while. 0:00:00.365 1M / 11M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.365 1M / 11M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 41.6666 Gb 0:00:00.365 1M / 11M INFO General (kmer_splitter.hpp : 101) Using cell size of 3355443 0:00:08.433 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 1255070 reads 0:00:13.105 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 2326191 reads 0:00:17.776 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 3402664 reads 0:00:22.475 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 4468625 reads 0:00:27.211 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 5530863 reads 0:00:31.958 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 6600483 reads 0:00:36.706 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 7673293 reads 0:00:41.348 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 8735552 reads 0:00:46.025 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 9807853 reads 0:01:09.393 1M / 582M INFO General (kmer_splitters.hpp : 131) Used 14683742 reads 0:01:09.394 1M / 582M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:01:12.571 1M / 582M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 6430255 kmers in total. 0:01:12.571 1M / 582M INFO General (stage.cpp : 117) PROCEDURE == Extension index construction (id: construction:extension_index_construction) 0:01:12.586 1M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 438) Building kmer index 0:01:12.586 1M / 582M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 10 files using 1 threads. This might take a while. 0:01:12.641 1M / 582M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:01:12.642 1M / 582M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 41.6666 Gb 0:01:12.642 1M / 582M INFO General (kmer_splitter.hpp : 101) Using cell size of 3355443 0:01:17.230 601M / 601M INFO General (kmer_splitters.hpp : 194) Processed 6430255 kmers 0:01:17.230 601M / 601M INFO General (kmer_splitters.hpp : 199) Used 6430255 kmers. 0:01:17.230 1M / 582M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:01:19.436 1M / 582M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 6417037 kmers in total. 0:01:19.436 1M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:01:20.222 5M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 6417037 kmers, 4642256 bytes occupied (5.78741 bits per kmer). 0:01:20.222 5M / 582M INFO General (kmer_index_builder.hpp : 169) Merging final buckets. 0:01:20.697 12M / 582M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 100) Building k-mer extensions from k+1-mers 0:01:21.994 12M / 582M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 105) Building k-mer extensions from k+1-mers finished. 0:01:21.996 12M / 582M INFO General (stage.cpp : 117) PROCEDURE == Early tip clipping (id: construction:early_tip_clipper) 0:01:21.996 12M / 582M INFO General (construction.cpp : 301) Early tip clipper length bound set as (RL - K) 0:01:21.996 12M / 582M INFO Early tip clipping (early_simplification.hpp : 47) Early tip clipping 0:01:23.415 22M / 582M INFO Early tip clipping (early_simplification.hpp : 82) #tipped junctions: 104301 0:01:23.438 22M / 582M INFO Early tip clipping (early_simplification.hpp : 93) Clipped tips: 104611 0:01:23.441 12M / 582M INFO Early tip clipping (early_simplification.hpp : 49) 744057 34-mers were removed by early tip clipper 0:01:23.441 12M / 582M INFO General (stage.cpp : 117) PROCEDURE == Condensing graph (id: construction:graph_condensing) 0:01:23.458 12M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths 0:01:25.008 15M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 45623 sequences extracted 0:01:25.830 15M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops 0:01:26.268 15M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 2 loops collected 0:01:26.272 15M / 582M INFO General (debruijn_graph_constructor: 487) Total 91250 edges to create 0:01:26.272 18M / 582M INFO General (debruijn_graph_constructor: 489) Collecting link records 0:01:26.290 20M / 582M INFO General (debruijn_graph_constructor: 491) Ordering link records 0:01:26.296 20M / 582M INFO General (debruijn_graph_constructor: 493) Sorting done 0:01:26.297 20M / 582M INFO General (debruijn_graph_constructor: 503) Total 32407 vertices to create 0:01:26.297 23M / 582M INFO General (debruijn_graph_constructor: 506) Connecting the graph 0:01:26.301 21M / 582M INFO General (stage.cpp : 117) PROCEDURE == Filling coverage indices (PHM) (id: construction:coverage_filling_phm) 0:01:26.301 21M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:01:27.035 25M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 6430255 kmers, 4651776 bytes occupied (5.78736 bits per kmer). 0:01:27.039 50M / 582M INFO General (coverage_hash_map_builder.: 47) Collecting k-mer coverage information from reads, this takes a while. 0:01:54.138 50M / 582M INFO General (construction.cpp : 430) Filling coverage and flanking coverage from PHM 0:01:55.132 50M / 582M INFO General (coverage_filling.hpp : 82) Processed 91183 edges 0:01:55.534 10M / 582M INFO StageManager (stage.cpp : 185) STAGE == EC Threshold Finding (id: ec_threshold_finder) 0:01:55.534 10M / 582M INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 3 0:01:55.534 10M / 582M INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 84 0:01:55.535 10M / 582M INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 84. Coverage mad: 16.3086 0:01:55.535 10M / 582M INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:01:55.603 10M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:01:55.779 10M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:01:56.390 10M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:01:57.676 10M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:01:58.395 10M / 582M INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 82.7077. Fitted coverage std. dev: 16.3853 0:01:58.397 10M / 582M INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.987645 0:01:58.397 10M / 582M INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 34 0:01:58.397 10M / 582M INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 34 0:01:58.397 10M / 582M INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 5207154 0:01:58.397 10M / 582M INFO General (genomic_info_filler.cpp : 55) Mean coverage was calculated as 82.7077 0:01:58.397 10M / 582M INFO General (genomic_info_filler.cpp : 70) EC coverage threshold value was calculated as 34 0:01:58.397 10M / 582M INFO General (genomic_info_filler.cpp : 71) Trusted kmer low bound: 0 0:01:58.397 10M / 582M INFO StageManager (stage.cpp : 185) STAGE == Raw Simplification (id: raw_simplification) 0:01:58.397 10M / 582M INFO General (simplification.cpp : 127) PROCEDURE == Initial cleaning 0:01:58.397 10M / 582M INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:01:58.397 10M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Self conjugate edge remover 0:01:58.401 10M / 582M INFO Simplification (parallel_processing.hpp : 170) Self conjugate edge remover triggered 0 times 0:01:58.401 10M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Initial tip clipper 0:01:58.407 10M / 582M INFO Simplification (parallel_processing.hpp : 170) Initial tip clipper triggered 258 times 0:01:58.407 10M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Initial ec remover 0:01:58.555 10M / 582M INFO Simplification (parallel_processing.hpp : 170) Initial ec remover triggered 12927 times 0:01:58.556 10M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Initial isolated edge remover 0:01:58.557 10M / 582M INFO Simplification (parallel_processing.hpp : 170) Initial isolated edge remover triggered 1454 times 0:01:58.557 9M / 582M INFO StageManager (stage.cpp : 185) STAGE == Simplification (id: simplification) 0:01:58.557 9M / 582M INFO General (simplification.cpp : 368) Graph simplification started 0:01:58.557 9M / 582M INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:01:58.557 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 1 0:01:58.557 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.559 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 20 times 0:01:58.559 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.574 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 1056 times 0:01:58.574 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 74 times 0:01:58.581 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 2 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 1 times 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 9 times 0:01:58.581 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 3 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 2 times 0:01:58.581 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 4 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.581 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 2 times 0:01:58.582 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 5 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:58.582 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 6 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:58.582 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 7 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:58.582 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 8 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 3 times 0:01:58.582 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 9 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 4 times 0:01:58.582 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 10 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 1 times 0:01:58.582 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 11 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.582 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 4 times 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:58.583 9M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 12 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:58.583 9M / 582M INFO StageManager (stage.cpp : 185) STAGE == Simplification Cleanup (id: simplification_cleanup) 0:01:58.583 9M / 582M INFO General (simplification.cpp : 176) PROCEDURE == Post simplification 0:01:58.583 9M / 582M INFO General (graph_simplification.hpp : 448) Disconnection of relatively low covered edges disabled 0:01:58.583 9M / 582M INFO General (graph_simplification.hpp : 485) Complex tip clipping disabled 0:01:58.583 9M / 582M INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:01:58.583 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.584 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.584 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.584 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.584 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:58.585 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:58.585 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:58.585 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:58.585 9M / 582M INFO General (simplification.cpp : 327) Disrupting self-conjugate edges 0:01:58.586 9M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Removing isolated edges 0:01:58.586 9M / 582M INFO Simplification (parallel_processing.hpp : 170) Removing isolated edges triggered 15 times 0:01:58.586 9M / 582M INFO General (simplification.cpp : 491) Counting average coverage 0:01:58.586 9M / 582M INFO General (simplification.cpp : 497) Average coverage = 86.1035 0:01:58.586 9M / 582M INFO StageManager (stage.cpp : 185) STAGE == Contig Output (id: contig_output) 0:01:59.050 9M / 582M INFO General (read_converter.cpp : 107) Outputting contigs to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K33/simplified_contigs 0:01:59.142 11M / 582M INFO General (binary_converter.cpp : 111) 1740 reads written 0:01:59.268 9M / 582M INFO General (pipeline.cpp : 287) SPAdes finished 0:01:59.269 1M / 582M INFO General (main.cpp : 136) Assembling time: 0 hours 1 minutes 59 seconds ===== K33 finished. ===== K55 started. == Running: /opt/software/SPAdes/3.15.3-GCC-11.2.0/bin/spades-core /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/configs/config.info 0:00:00.000 1M / 11M INFO General (main.cpp : 99) Loaded config from /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/configs/config.info 0:00:00.000 1M / 11M INFO General (memory_limit.cpp : 48) Memory limit set to 125 Gb 0:00:00.000 1M / 11M INFO General (main.cpp : 107) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 1M / 11M INFO General (main.cpp : 108) Maximum k-mer length: 128 0:00:00.000 1M / 11M INFO General (main.cpp : 109) Assembling dataset (/glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/dataset.info) with K=55 0:00:00.000 1M / 11M INFO General (main.cpp : 110) Maximum # of threads to use (adjusted due to OMP capabilities): 1 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 212) SPAdes started 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 225) Starting from stage: read_conversion 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 231) Two-step repeat resolution disabled 0:00:00.000 1M / 11M INFO GraphCore (graph_core.hpp : 672) Graph created, vertex min_id: 3, edge min_id: 3 0:00:00.000 1M / 11M INFO GraphCore (graph_core.hpp : 673) Vertex size: 48, edge size: 40 0:00:00.000 1M / 11M INFO General (edge_index.hpp : 113) Size of edge index entries: 12/8 0:00:00.000 1M / 11M INFO General (pipeline.cpp : 242) Will need read mapping, kmer mapper will be attached 0:00:00.000 1M / 11M INFO StageManager (stage.cpp : 185) STAGE == Binary Read Conversion (id: read_conversion) 0:00:00.001 1M / 11M INFO General (read_converter.cpp : 53) Binary reads detected 0:00:00.001 1M / 11M INFO StageManager (stage.cpp : 185) STAGE == de Bruijn graph construction (id: construction) 0:00:00.001 1M / 11M INFO General (construction.cpp : 118) Contigs from previous K will be used: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K33/simplified_contigs 0:00:00.265 1M / 11M INFO General (construction.cpp : 153) Max read length 101 0:00:00.265 1M / 11M INFO General (construction.cpp : 159) Average read length 94.5203 0:00:00.265 1M / 11M INFO General (stage.cpp : 117) PROCEDURE == k+1-mer counting (id: construction:kpomer_counting) 0:00:00.265 1M / 11M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 10 files using 1 threads. This might take a while. 0:00:00.330 1M / 11M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.330 1M / 11M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 41.6666 Gb 0:00:00.330 1M / 11M INFO General (kmer_splitter.hpp : 101) Using cell size of 3355443 0:00:08.021 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 1892644 reads 0:00:12.970 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 3547189 reads 0:00:17.987 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 5186067 reads 0:00:22.912 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 6828523 reads 0:00:27.825 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 8477038 reads 0:00:32.712 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 10113627 reads 0:00:37.614 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 11757873 reads 0:00:42.498 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 13402792 reads 0:00:48.094 601M / 601M INFO General (kmer_splitters.hpp : 125) Processed 14680904 reads 0:00:48.094 1M / 582M INFO General (kmer_splitters.hpp : 131) Used 14680904 reads 0:00:48.095 1M / 582M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:00:50.877 1M / 582M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 6516721 kmers in total. 0:00:50.877 1M / 582M INFO General (stage.cpp : 117) PROCEDURE == Extension index construction (id: construction:extension_index_construction) 0:00:50.893 1M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 438) Building kmer index 0:00:50.893 1M / 582M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 10 files using 1 threads. This might take a while. 0:00:51.023 1M / 582M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:51.023 1M / 582M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 41.6666 Gb 0:00:51.023 1M / 582M INFO General (kmer_splitter.hpp : 101) Using cell size of 3355443 0:00:55.632 601M / 601M INFO General (kmer_splitters.hpp : 194) Processed 6516721 kmers 0:00:55.633 601M / 601M INFO General (kmer_splitters.hpp : 199) Used 6516721 kmers. 0:00:55.633 1M / 582M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:00:57.679 1M / 582M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 6519748 kmers in total. 0:00:57.679 1M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:00:58.456 5M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 6519748 kmers, 4716392 bytes occupied (5.78721 bits per kmer). 0:00:58.456 5M / 582M INFO General (kmer_index_builder.hpp : 169) Merging final buckets. 0:00:58.956 12M / 582M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 100) Building k-mer extensions from k+1-mers 0:01:00.286 12M / 582M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 105) Building k-mer extensions from k+1-mers finished. 0:01:00.288 12M / 582M INFO General (stage.cpp : 117) PROCEDURE == Condensing graph (id: construction:graph_condensing) 0:01:00.297 12M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths 0:01:02.211 23M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 226445 sequences extracted 0:01:03.260 23M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops 0:01:03.701 23M / 582M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 0 loops collected 0:01:03.707 23M / 582M INFO General (debruijn_graph_constructor: 487) Total 452890 edges to create 0:01:03.708 41M / 582M INFO General (debruijn_graph_constructor: 489) Collecting link records 0:01:03.810 48M / 582M INFO General (debruijn_graph_constructor: 491) Ordering link records 0:01:03.843 48M / 582M INFO General (debruijn_graph_constructor: 493) Sorting done 0:01:03.846 50M / 582M INFO General (debruijn_graph_constructor: 503) Total 229472 vertices to create 0:01:03.846 72M / 582M INFO General (debruijn_graph_constructor: 506) Connecting the graph 0:01:03.886 60M / 582M INFO General (stage.cpp : 117) PROCEDURE == Filling coverage indices (PHM) (id: construction:coverage_filling_phm) 0:01:03.886 60M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:01:04.639 64M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 6516721 kmers, 4714256 bytes occupied (5.78727 bits per kmer). 0:01:04.641 89M / 582M INFO General (coverage_hash_map_builder.: 47) Collecting k-mer coverage information from reads, this takes a while. 0:01:23.714 89M / 582M INFO General (construction.cpp : 430) Filling coverage and flanking coverage from PHM 0:01:25.013 89M / 582M INFO General (coverage_filling.hpp : 82) Processed 452856 edges 0:01:25.434 49M / 582M INFO StageManager (stage.cpp : 185) STAGE == EC Threshold Finding (id: ec_threshold_finder) 0:01:25.434 49M / 582M INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 0:01:25.434 49M / 582M INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 54 0:01:25.434 49M / 582M INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 54. Coverage mad: 13.3434 0:01:25.435 49M / 582M INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:01:25.480 49M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:01:25.592 49M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:01:25.929 49M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:01:26.830 49M / 582M INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:01:27.394 49M / 582M INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 53.6758. Fitted coverage std. dev: 12.1603 0:01:27.395 49M / 582M INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.957965 0:01:27.395 49M / 582M INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 20 0:01:27.395 49M / 582M INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 20 0:01:27.395 49M / 582M INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 5247137 0:01:27.395 49M / 582M INFO General (genomic_info_filler.cpp : 55) Mean coverage was calculated as 53.6758 0:01:27.395 49M / 582M INFO General (genomic_info_filler.cpp : 70) EC coverage threshold value was calculated as 20 0:01:27.395 49M / 582M INFO General (genomic_info_filler.cpp : 71) Trusted kmer low bound: 0 0:01:27.395 49M / 582M INFO StageManager (stage.cpp : 185) STAGE == Gap Closer (id: early_gapcloser) 0:01:27.397 58M / 582M INFO General (edge_index.hpp : 113) Size of edge index entries: 12/8 0:01:27.457 63M / 582M INFO General (gap_closer.cpp : 101) Total edges in tip neighborhood: 118497 out of 452856, length: 1315498 0:01:27.461 64M / 582M INFO General (edge_index.hpp : 167) Using small index (max_id = 455157) 0:01:27.539 64M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:01:27.899 65M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 1201811 kmers, 868752 bytes occupied (5.78295 bits per kmer). 0:01:27.900 75M / 582M INFO General (edge_index_builders.hpp : 265) Collecting edge information from graph, this takes a while. 0:01:29.332 74M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 200000 reads 0:01:30.607 74M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 400000 reads 0:01:31.878 74M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 600000 reads 0:01:33.161 74M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 800000 reads 0:01:34.457 74M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1000000 reads 0:01:35.780 74M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1200000 reads 0:01:42.377 75M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 2200000 reads 0:01:51.346 75M / 582M INFO General (sequence_mapper_notifier.h: 95) Total 3437338 reads processed 0:01:51.364 61M / 582M INFO General (gap_closer.cpp : 452) Initializing gap closer 0:01:51.364 61M / 582M INFO GapCloser (gap_closer.cpp : 359) Closing short gaps 0:01:51.476 61M / 582M INFO GapCloser (gap_closer.cpp : 391) Closing short gaps complete: filled 1 gaps after checking 25 candidates 0:01:51.482 61M / 582M INFO General (gap_closer.cpp : 456) Gap closer done 0:01:51.485 49M / 582M INFO StageManager (stage.cpp : 185) STAGE == Raw Simplification (id: raw_simplification) 0:01:51.485 49M / 582M INFO General (simplification.cpp : 127) PROCEDURE == Initial cleaning 0:01:51.485 49M / 582M INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:01:51.485 49M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Self conjugate edge remover 0:01:51.508 49M / 582M INFO Simplification (parallel_processing.hpp : 170) Self conjugate edge remover triggered 0 times 0:01:51.508 49M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Initial tip clipper 0:01:52.025 43M / 582M INFO Simplification (parallel_processing.hpp : 170) Initial tip clipper triggered 110016 times 0:01:52.025 43M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Initial ec remover 0:01:52.054 43M / 582M INFO Simplification (parallel_processing.hpp : 170) Initial ec remover triggered 276 times 0:01:52.054 43M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Initial isolated edge remover 0:01:52.060 43M / 582M INFO Simplification (parallel_processing.hpp : 170) Initial isolated edge remover triggered 4151 times 0:01:52.060 42M / 582M INFO StageManager (stage.cpp : 185) STAGE == Simplification (id: simplification) 0:01:52.060 42M / 582M INFO General (simplification.cpp : 368) Graph simplification started 0:01:52.060 42M / 582M INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:01:52.060 42M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 1 0:01:52.060 42M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.061 42M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 1 times 0:01:52.062 42M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.095 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 451 times 0:01:52.095 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:52.097 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 2 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 7 times 0:01:52.097 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 3 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.097 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 2 times 0:01:52.098 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 4 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 3 times 0:01:52.098 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 5 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:52.098 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 6 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:52.098 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 7 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:52.098 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 8 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:52.098 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 9 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 1 times 0:01:52.098 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 10 0:01:52.098 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.099 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.099 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.099 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.099 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.099 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 1 times 0:01:52.099 46M / 582M INFO General (simplification.cpp : 373) PROCEDURE == Simplification cycle, iteration 11 0:01:52.099 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:01:52.100 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:01:52.100 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:01:52.101 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:01:52.101 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Low coverage edge remover 0:01:52.102 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Low coverage edge remover triggered 0 times 0:01:52.103 46M / 582M INFO StageManager (stage.cpp : 185) STAGE == Gap Closer (id: late_gapcloser) 0:01:52.105 55M / 582M INFO General (edge_index.hpp : 113) Size of edge index entries: 12/8 0:01:52.105 55M / 582M INFO General (gap_closer.cpp : 101) Total edges in tip neighborhood: 9 out of 2271, length: 136248 0:01:52.105 55M / 582M INFO General (edge_index.hpp : 167) Using small index (max_id = 455157) 0:01:52.110 55M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:01:52.137 55M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 135882 kmers, 98880 bytes occupied (5.82152 bits per kmer). 0:01:52.137 56M / 582M INFO General (edge_index_builders.hpp : 265) Collecting edge information from graph, this takes a while. 0:01:54.110 56M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 200000 reads 0:01:56.052 56M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 400000 reads 0:01:58.009 56M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 600000 reads 0:01:59.992 56M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 800000 reads 0:02:02.062 56M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1000000 reads 0:02:04.057 56M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1200000 reads 0:02:13.616 56M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 2200000 reads 0:02:26.707 56M / 582M INFO General (sequence_mapper_notifier.h: 95) Total 3437338 reads processed 0:02:26.710 55M / 582M INFO General (gap_closer.cpp : 452) Initializing gap closer 0:02:26.710 55M / 582M INFO GapCloser (gap_closer.cpp : 359) Closing short gaps 0:02:26.711 55M / 582M INFO GapCloser (gap_closer.cpp : 391) Closing short gaps complete: filled 0 gaps after checking 6 candidates 0:02:26.711 55M / 582M INFO General (gap_closer.cpp : 456) Gap closer done 0:02:26.712 46M / 582M INFO StageManager (stage.cpp : 185) STAGE == Simplification Cleanup (id: simplification_cleanup) 0:02:26.712 46M / 582M INFO General (simplification.cpp : 176) PROCEDURE == Post simplification 0:02:26.712 46M / 582M INFO General (graph_simplification.hpp : 448) Disconnection of relatively low covered edges disabled 0:02:26.712 46M / 582M INFO General (graph_simplification.hpp : 485) Complex tip clipping disabled 0:02:26.712 46M / 582M INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:02:26.712 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:02:26.714 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:02:26.714 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:02:26.715 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:02:26.715 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Tip clipper 0:02:26.716 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Tip clipper triggered 0 times 0:02:26.716 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Bulge remover 0:02:26.718 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Bulge remover triggered 0 times 0:02:26.718 46M / 582M INFO General (simplification.cpp : 327) Disrupting self-conjugate edges 0:02:26.718 46M / 582M INFO Simplification (parallel_processing.hpp : 167) Running Removing isolated edges 0:02:26.720 46M / 582M INFO Simplification (parallel_processing.hpp : 170) Removing isolated edges triggered 1 times 0:02:26.720 46M / 582M INFO General (simplification.cpp : 491) Counting average coverage 0:02:26.720 46M / 582M INFO General (simplification.cpp : 497) Average coverage = 55.4179 0:02:26.720 46M / 582M INFO StageManager (stage.cpp : 185) STAGE == Mismatch Correction (id: mismatch_correction) 0:02:26.720 46M / 582M INFO General (graph_pack.cpp : 67) Index refill 0:02:26.720 46M / 582M INFO General (edge_index.hpp : 156) Using small index (max_id = 455157) 0:02:26.912 46M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:02:28.143 50M / 582M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 5269505 kmers, 3806704 bytes occupied (5.77922 bits per kmer). 0:02:28.148 94M / 582M INFO General (edge_index_builders.hpp : 252) Collecting edge information from graph, this takes a while. 0:02:28.820 94M / 582M INFO General (graph_pack.cpp : 77) Normalizing k-mer map. Total 71544 kmers to process 0:02:28.838 94M / 582M INFO General (graph_pack.cpp : 79) Normalizing done 0:02:28.838 94M / 582M INFO General (mismatch_correction.cpp : 400) Collect potential mismatches 0:02:28.888 94M / 582M INFO General (mismatch_correction.cpp : 192) Total 480 edges (out of 2269) with 3694 potential mismatch positions (7.69583 positions per edge) 0:02:28.888 94M / 582M INFO General (mismatch_correction.cpp : 402) Potential mismatches collected 0:02:29.111 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 200000 reads 0:02:29.313 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 400000 reads 0:02:29.520 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 600000 reads 0:02:29.733 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 800000 reads 0:02:29.986 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1000000 reads 0:02:30.199 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1200000 reads 0:02:31.357 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 2200000 reads 0:02:33.681 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 4200000 reads 0:02:38.837 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 8400000 reads 0:02:46.763 94M / 582M INFO General (sequence_mapper_notifier.h: 95) Total 14677424 reads processed 0:02:46.767 94M / 582M INFO General (mismatch_correction.cpp : 395) All edges processed 0:02:46.767 94M / 582M INFO General (mismatch_correction.cpp : 450) Corrected 4 nucleotides 0:02:46.767 94M / 582M INFO StageManager (stage.cpp : 185) STAGE == Contig Output (id: contig_output) 0:02:46.767 94M / 582M INFO General (contig_output.hpp : 16) Outputting contigs to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/before_rr.fasta 0:02:47.039 94M / 582M INFO General (contig_output_stage.cpp : 151) Writing GFA graph to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/assembly_graph_after_simplification.gfa 0:02:47.067 94M / 582M INFO StageManager (stage.cpp : 185) STAGE == Paired Information Counting (id: late_pair_info_count) 0:02:47.070 94M / 582M INFO General (graph_pack.cpp : 77) Normalizing k-mer map. Total 71732 kmers to process 0:02:47.090 94M / 582M INFO General (graph_pack.cpp : 79) Normalizing done 0:02:47.090 94M / 582M INFO General (pair_info_count.cpp : 339) Min edge length for estimation: 58577 0:02:47.090 94M / 582M INFO General (pair_info_count.cpp : 350) Estimating insert size for library #0 0:02:47.090 94M / 582M INFO General (pair_info_count.cpp : 202) Estimating insert size (takes a while) 0:02:47.100 126M / 582M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:02:47.564 126M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 200000 reads 0:02:48.025 126M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 400000 reads 0:02:48.527 126M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 600000 reads 0:02:49.006 126M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 800000 reads 0:02:49.553 126M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1000000 reads 0:02:50.040 126M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1200000 reads 0:02:52.555 126M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 2200000 reads 0:02:55.708 126M / 582M INFO General (sequence_mapper_notifier.h: 95) Total 3437338 reads processed 0:02:55.896 126M / 582M INFO General (pair_info_count.cpp : 220) Edge pairs: 17078 0:02:55.896 126M / 582M INFO General (pair_info_count.cpp : 222) 1562310 paired reads (45.4512% of all) aligned to long edges 0:02:55.897 94M / 582M INFO General (pair_info_count.cpp : 369) Insert size = 196.892, deviation = 12.4293, left quantile = 184, right quantile = 210, read length = 101 0:02:55.897 94M / 582M INFO General (pair_info_count.cpp : 390) Filtering data for library #0 0:02:55.909 94M / 582M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:02:56.393 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 200000 reads 0:02:56.846 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 400000 reads 0:02:57.342 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 600000 reads 0:02:57.813 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 800000 reads 0:02:58.329 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1000000 reads 0:02:58.805 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1200000 reads 0:03:01.222 94M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 2200000 reads 0:03:04.303 94M / 582M INFO General (sequence_mapper_notifier.h: 95) Total 3437338 reads processed 0:03:04.304 94M / 582M INFO General (pair_info_count.cpp : 402) Mapping library #0 0:03:04.304 94M / 582M INFO General (pair_info_count.cpp : 404) Mapping paired reads (takes a while) 0:03:04.304 94M / 582M INFO General (pair_info_count.cpp : 299) Left insert size quantile 184, right insert size quantile 210, filtering threshold 2, rounding threshold 0 0:03:04.317 103M / 582M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:03:04.826 103M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 200000 reads 0:03:05.321 103M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 400000 reads 0:03:05.878 103M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 600000 reads 0:03:06.395 104M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 800000 reads 0:03:06.958 104M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1000000 reads 0:03:07.477 104M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 1200000 reads 0:03:10.132 104M / 582M INFO General (sequence_mapper_notifier.h: 77) Processed 2200000 reads 0:03:13.651 105M / 582M INFO General (sequence_mapper_notifier.h: 95) Total 3437338 reads processed 0:03:13.655 96M / 582M INFO StageManager (stage.cpp : 185) STAGE == Distance Estimation (id: distance_estimation) 0:03:13.655 96M / 582M INFO General (distance_estimation.cpp : 179) Processing library #0 0:03:13.655 96M / 582M INFO General (distance_estimation.cpp : 150) Weight Filter Done 0:03:13.655 96M / 582M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 0:03:13.666 96M / 582M INFO General (distance_estimation.cpp : 37) Filtering info 0:03:13.666 96M / 582M INFO General (pair_info_filters.hpp : 242) Start filtering; library index size: 8891 0:03:13.668 97M / 582M INFO General (pair_info_filters.hpp : 263) Done filtering; library index size: 8014 0:03:13.668 96M / 582M INFO General (distance_estimation.cpp : 156) Refining clustered pair information 0:03:13.669 96M / 582M INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 0:03:13.669 96M / 582M INFO General (distance_estimation.cpp : 160) Improving paired information 0:03:13.680 96M / 582M INFO PairInfoImprover (pair_info_improver.hpp : 104) Paired info stats: missing = 208; contradictional = 18 0:03:13.692 96M / 582M INFO PairInfoImprover (pair_info_improver.hpp : 104) Paired info stats: missing = 4; contradictional = 8 0:03:13.692 96M / 582M INFO General (distance_estimation.cpp : 104) Filling scaffolding index 0:03:13.692 96M / 582M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator 0:03:13.712 96M / 582M INFO General (distance_estimation.cpp : 37) Filtering info 0:03:13.712 96M / 582M INFO General (pair_info_filters.hpp : 242) Start filtering; library index size: 2359 0:03:13.712 96M / 582M INFO General (pair_info_filters.hpp : 263) Done filtering; library index size: 2359 0:03:13.712 96M / 582M INFO General (distance_estimation.cpp : 186) Clearing raw paired index 0:03:13.713 94M / 582M INFO StageManager (stage.cpp : 185) STAGE == Repeat Resolving (id: repeat_resolving) 0:03:13.713 94M / 582M INFO General (repeat_resolving.cpp : 87) Using Path-Extend repeat resolving 0:03:13.713 94M / 582M INFO General (launcher.cpp : 600) ExSPAnder repeat resolving tool started 0:03:14.139 94M / 582M INFO General (coverage_uniformity_analyz: 25) genomic coverage is 55.9677 calculated of length 5105071 0:03:14.139 94M / 582M WARN General (launcher.cpp : 178) Your data seems to have high uniform coverage depth. It is strongly recommended to use --isolate option. 0:03:14.141 99M / 582M INFO General (launcher.cpp : 418) Creating main extenders, unique edge length = 2000 0:03:14.141 99M / 582M INFO General (extenders_logic.cpp : 334) Estimated coverage of library #0 is 55.4179 0:03:14.141 99M / 582M INFO General (extenders_logic.cpp : 345) Creating extender; library index size: 8412 0:03:14.141 99M / 582M INFO General (extenders_logic.cpp : 334) Estimated coverage of library #0 is 55.4179 0:03:14.141 99M / 582M INFO General (extenders_logic.cpp : 345) Creating extender; library index size: 8412 0:03:14.141 99M / 582M INFO General (extenders_logic.cpp : 543) Using 1 paired-end library 0:03:14.141 99M / 582M INFO General (extenders_logic.cpp : 544) Using 1 paired-end scaffolding library 0:03:14.141 99M / 582M INFO General (extenders_logic.cpp : 545) Using 0 single read libraries 0:03:14.141 99M / 582M INFO General (launcher.cpp : 447) Total number of extenders is 3 0:03:14.141 99M / 582M INFO General (path_extenders.cpp : 36) Processed 0 paths from 1096 (0%) 0:03:14.149 101M / 582M INFO General (path_extenders.cpp : 36) Processed 110 paths from 1096 (10%) 0:03:14.150 101M / 582M INFO General (path_extenders.cpp : 34) Processed 128 paths from 1096 (11%) 0:03:14.155 102M / 582M INFO General (path_extenders.cpp : 36) Processed 220 paths from 1096 (20%) 0:03:14.156 102M / 582M INFO General (path_extenders.cpp : 34) Processed 256 paths from 1096 (23%) 0:03:14.157 102M / 582M INFO General (path_extenders.cpp : 36) Processed 330 paths from 1096 (30%) 0:03:14.160 103M / 582M INFO General (path_extenders.cpp : 36) Processed 440 paths from 1096 (40%) 0:03:14.162 103M / 582M INFO General (path_extenders.cpp : 34) Processed 512 paths from 1096 (46%) 0:03:14.162 103M / 582M INFO General (path_extenders.cpp : 36) Processed 550 paths from 1096 (50%) 0:03:14.164 103M / 582M INFO General (path_extenders.cpp : 36) Processed 660 paths from 1096 (60%) 0:03:14.166 104M / 582M INFO General (path_extenders.cpp : 36) Processed 770 paths from 1096 (70%) 0:03:14.168 104M / 582M INFO General (path_extenders.cpp : 36) Processed 880 paths from 1096 (80%) 0:03:14.168 104M / 582M INFO General (path_extenders.cpp : 36) Processed 990 paths from 1096 (90%) 0:03:14.168 104M / 582M INFO General (path_extenders.cpp : 34) Processed 1024 paths from 1096 (93%) 0:03:14.168 104M / 582M INFO General (launcher.cpp : 250) Finalizing paths 0:03:14.168 104M / 582M INFO General (launcher.cpp : 252) Deduplicating paths 0:03:14.169 104M / 582M INFO General (launcher.cpp : 256) Paths deduplicated 0:03:14.169 104M / 582M INFO PEResolver (pe_resolver.cpp : 60) Removing overlaps 0:03:14.169 104M / 582M INFO PEResolver (pe_resolver.cpp : 63) Sorting paths 0:03:14.169 104M / 582M INFO PEResolver (pe_resolver.cpp : 70) Marking overlaps 0:03:14.169 104M / 582M INFO OverlapRemover (overlap_remover.hpp : 116) Marking start/end overlaps 0:03:14.172 104M / 582M INFO OverlapRemover (overlap_remover.hpp : 119) Marking remaining overlaps 0:03:14.174 104M / 582M INFO PEResolver (pe_resolver.cpp : 73) Splitting paths 0:03:14.175 106M / 582M INFO PEResolver (pe_resolver.cpp : 78) Deduplicating paths 0:03:14.176 104M / 582M INFO PEResolver (pe_resolver.cpp : 80) Overlaps removed 0:03:14.177 104M / 582M INFO General (launcher.cpp : 273) Paths finalized 0:03:14.177 104M / 582M INFO General (launcher.cpp : 454) Closing gaps in paths 0:03:14.177 106M / 582M INFO General (launcher.cpp : 484) Gap closing completed 0:03:14.177 106M / 582M INFO General (launcher.cpp : 302) Traversing tandem repeats 0:03:14.179 106M / 582M INFO General (launcher.cpp : 312) Traversed 1 loops 0:03:14.179 106M / 582M INFO General (launcher.cpp : 250) Finalizing paths 0:03:14.179 106M / 582M INFO General (launcher.cpp : 252) Deduplicating paths 0:03:14.180 106M / 582M INFO General (launcher.cpp : 256) Paths deduplicated 0:03:14.180 106M / 582M INFO PEResolver (pe_resolver.cpp : 60) Removing overlaps 0:03:14.180 106M / 582M INFO PEResolver (pe_resolver.cpp : 63) Sorting paths 0:03:14.180 106M / 582M INFO PEResolver (pe_resolver.cpp : 70) Marking overlaps 0:03:14.180 106M / 582M INFO OverlapRemover (overlap_remover.hpp : 116) Marking start/end overlaps 0:03:14.180 106M / 582M INFO OverlapRemover (overlap_remover.hpp : 119) Marking remaining overlaps 0:03:14.180 106M / 582M INFO PEResolver (pe_resolver.cpp : 73) Splitting paths 0:03:14.180 106M / 582M INFO PEResolver (pe_resolver.cpp : 78) Deduplicating paths 0:03:14.180 106M / 582M INFO PEResolver (pe_resolver.cpp : 80) Overlaps removed 0:03:14.181 106M / 582M INFO General (launcher.cpp : 273) Paths finalized 0:03:14.181 106M / 582M INFO General (launcher.cpp : 664) ExSPAnder repeat resolving tool finished 0:03:14.183 96M / 582M INFO StageManager (stage.cpp : 185) STAGE == Contig Output (id: contig_output) 0:03:14.183 96M / 582M INFO General (contig_output.hpp : 16) Outputting contigs to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/before_rr.fasta 0:03:14.371 96M / 582M INFO General (contig_output_stage.cpp : 151) Writing GFA graph to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/assembly_graph_with_scaffolds.gfa 0:03:14.399 96M / 582M INFO General (contig_output_stage.cpp : 165) Outputting FastG graph to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/assembly_graph.fastg 0:03:14.635 96M / 582M INFO General (contig_output_stage.cpp : 196) Breaking scaffolds 0:03:14.647 104M / 582M INFO General (contig_output_stage.cpp : 98) Outputting contigs to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/final_contigs.fasta 0:03:14.755 104M / 582M INFO General (contig_output_stage.cpp : 104) Outputting FastG paths to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/final_contigs.paths 0:03:14.865 102M / 582M INFO General (contig_output_stage.cpp : 98) Outputting contigs to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/scaffolds.fasta 0:03:14.984 102M / 582M INFO General (contig_output_stage.cpp : 104) Outputting FastG paths to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/scaffolds.paths 0:03:15.102 102M / 582M INFO General (contig_output_stage.cpp : 111) Populating GFA with scaffold paths 0:03:15.201 96M / 582M INFO General (pipeline.cpp : 287) SPAdes finished 0:03:15.207 1M / 582M INFO General (main.cpp : 136) Assembling time: 0 hours 3 minutes 15 seconds ===== K55 finished. ===== Copy files started. == Running: /opt/software/Python/3.9.6-GCCcore-11.2.0/bin/python /opt/software/SPAdes/3.15.3-GCC-11.2.0/share/spades/spades_pipeline/scripts/copy_files.py /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/before_rr.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/before_rr.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/assembly_graph_after_simplification.gfa /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/assembly_graph_after_simplification.gfa /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/final_contigs.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/contigs.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/first_pe_contigs.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/first_pe_contigs.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/strain_graph.gfa /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/strain_graph.gfa /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/scaffolds.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/scaffolds.fasta /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/scaffolds.paths /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/scaffolds.paths /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/assembly_graph_with_scaffolds.gfa /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/assembly_graph_with_scaffolds.gfa /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/assembly_graph.fastg /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/assembly_graph.fastg /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/K55/final_contigs.paths /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/contigs.paths ===== Copy files finished. ===== Assembling finished. ===== Breaking scaffolds started. == Running: /opt/software/Python/3.9.6-GCCcore-11.2.0/bin/python /opt/software/SPAdes/3.15.3-GCC-11.2.0/share/spades/spades_pipeline/scripts/breaking_scaffolds_script.py --result_scaffolds_filename /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/scaffolds.fasta --misc_dir /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/misc --threshold_for_breaking_scaffolds 3 ===== Breaking scaffolds finished. ===== Terminate started. ===== Terminate finished. * Corrected reads are in /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/corrected/ * Assembled contigs are in /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/contigs.fasta * Assembled scaffolds are in /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/scaffolds.fasta * Paths in the assembly graph corresponding to the contigs are in /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/contigs.paths * Paths in the assembly graph corresponding to the scaffolds are in /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/scaffolds.paths * Assembly graph is in /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/assembly_graph.fastg * Assembly graph in GFA format is in /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/assembly_graph_with_scaffolds.gfa ======= SPAdes pipeline finished WITH WARNINGS! === Error correction and assembling warnings: * 0:03:14.139 94M / 582M WARN General (launcher.cpp : 178) Your data seems to have high uniform coverage depth. It is strongly recommended to use --isolate option. ======= Warnings saved to /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/warnings.log SPAdes log can be found here: /glfs/brick01/gv0/mramseylab/TnSeq_THP/snakemake/Snakemake_Training/01_genome/spades.log Thank you for using SPAdes! [Wed Apr 19 11:20:58 2023] Finished job 0. 1 of 1 steps (100%) done