test various spades-dependent tools

[jennaj]

Testing all installed at usegalaxy.org

Not sure how this will technically work with multiple tests, all at once in one ticket-- starting off with four

[jennaj]

/run-tool-test tool_id=toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill/1.1.0+galaxy1

[jennaj]

/run-tool-test tool_id=toolshed.g2.bx.psu.edu/repos/nml/spades/spades/3.15.3+galaxy2

[jennaj]

/run-tool-test tool_id=toolshed.g2.bx.psu.edu/repos/nml/metaspades/metaspades/3.15.3+galaxy2

[jennaj]

/run-tool-test tool_id=toolshed.g2.bx.psu.edu/repos/iuc/spades_metaviralspades/spades_metaviralspades/3.15.4+galaxy0

[mvdbeek]

Results (powered by Planemo)

Summary

State	Count
Total	6
Passed	5
Error	1
Failure	0
Skipped	0

Errored s

*

❌ toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill (Test #6)

**Execution Problem:** * ``` Input staging problem: Expecting value: line 1 column 1 (char 0) ```

Passed s

*

✅ toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill (Test #1)

**Command Line:** * ```console ``` **Exit Code:** * ```console 0 ``` **Standard Error:** * ```console [shovill] Hello g2main [shovill] You ran: /usr/local/bin/shovill --outdir out --cpus 6 --ram 29 --R1 fastq_r1.fastqsanger --R2 fastq_r2.fastqsanger --namefmt contig%05d --depth 100 --nocorr --minlen 0 --mincov 2 --assembler spades [shovill] This is shovill 1.1.0 [shovill] Written by Torsten Seemann [shovill] Homepage is https://github.com/tseemann/shovill [shovill] Operating system is linux [shovill] Perl version is v5.26.2 [shovill] Machine has 10 CPU cores and 29.29 GB RAM [shovill] Using bwa - /usr/local/bin/bwa | Version: 0.7.17-r1188 [shovill] Using flash - /usr/local/bin/flash | FLASH v1.2.11 [shovill] Using java - /usr/local/bin/java | openjdk version "11.0.1" 2018-10-16 LTS [shovill] Using kmc - /usr/local/bin/kmc | K-Mer Counter (KMC) ver. 3.1.1 (2019-05-19) [shovill] Using lighter - /usr/local/bin/lighter | Lighter v1.1.2 [shovill] Using megahit - /usr/local/bin/megahit | MEGAHIT v1.2.9 [shovill] Using megahit_toolkit - /usr/local/bin/megahit_toolkit | v1.2.9 [shovill] Using pigz - /usr/local/bin/pigz | pigz 2.6 [shovill] Using pilon - /usr/local/bin/pilon | Pilon version 1.23 Mon Nov 26 16:04:05 2018 -0500 [shovill] Using samclip - /usr/local/bin/samclip | samclip 0.4.0 [shovill] Using samtools - /usr/local/bin/samtools | Version: 1.12 (using htslib 1.12) [shovill] Using seqtk - /usr/local/bin/seqtk | Version: 1.3-r106 [shovill] Using skesa - /usr/local/bin/skesa | SKESA 2.4.0 [shovill] Using spades.py - /usr/local/bin/spades.py | SPAdes genome assembler v3.14.1 [shovill] Using trimmomatic - /usr/local/bin/trimmomatic | 0.39 [shovill] Using velvetg - /usr/local/bin/velvetg | Version 1.2.10 [shovill] Using velveth - /usr/local/bin/velveth | Version 1.2.10 [shovill] Found spades version: 003014000 [shovill] Will use spades 003014000 options: --isolate and --merged [shovill] Using tempdir: /corral4/main/jobs/044/273/44273377/_job_tmp [shovill] Changing into folder: /corral4/main/jobs/044/273/44273377/working/out [shovill] Collecting raw read statistics with 'seqtk' [shovill] Running: seqtk fqchk -q3 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat >/corral4/main/jobs/044/273/44273377/_job_tmp/cLZWrBilOd 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Read stats: min_len = 150 [shovill] Read stats: total_bp = 300000 [shovill] Read stats: max_len = 150 [shovill] Read stats: avg_len = 150 [shovill] Estimating genome size by counting unqiue 21-mers > frequency 10 [shovill] Running: kmc -sm -m14 -t6 -k21 -ci10 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat /corral4/main/jobs/044/273/44273377/_job_tmp/f4wtX103_c/kmc /corral4/main/jobs/044/273/44273377/_job_tmp/f4wtX103_c 2>&1 | sed 's/^/[kmc] /' | tee -a shovill.log [shovill] Using genome size 1188 bp [shovill] Estimated sequencing depth: 252 x [shovill] Subsampling reads by factor 0.397 to get from 252x to 100x [shovill] Running: seqtk sample \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat 0.397 | pigz --fast -c -p 6 > R1.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Running: seqtk sample \/corral4\/main\/objects\/3\/6\/e\/dataset_36e11e53\-e2b5\-46ec\-bb32\-f57f5aa02e03\.dat 0.397 | pigz --fast -c -p 6 > R2.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Appending -Xmx29g to _JAVA_OPTIONS [shovill] Running: ln -sf R1\.sub\.fq\.gz R1.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Running: ln -sf R2\.sub\.fq\.gz R2.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Average read length looks like 150 bp [shovill] Automatically setting --minlen to 75 [shovill] Setting k-mer range to (31 .. 112) [shovill] Estimated K-mers: 31 51 71 91 111 [kn=5, ks=20, kmin=31, kmax=112] [shovill] Using kmers: 31,51,71,91,111 [shovill] Correcting reads with 'Lighter' [shovill] Running: lighter -od . -r R1.fq.gz -r R2.fq.gz -K 32 1188 -t 6 -maxcor 1 2>&1 | sed 's/^/[lighter] /' | tee -a shovill.log [shovill] Overlapping/stitching PE reads with 'FLASH' [shovill] Running: flash -m 20 -M 150 -d . -o flash -z -t 6 R1.cor.fq.gz R2.cor.fq.gz 2>&1 | sed 's/^//' | tee -a shovill.log [shovill] Assembling reads with 'spades' [shovill] Running: spades.py -1 flash.notCombined_1.fastq.gz -2 flash.notCombined_2.fastq.gz --isolate --threads 6 --memory 29 -o spades --tmp-dir /corral4/main/jobs/044/273/44273377/_job_tmp -k 31,51,71,91,111 --merged flash.extendedFrags.fastq.gz 2>&1 | sed 's/^/[spades] /' | tee -a shovill.log [shovill] User supplied --nocorr, so not correcting contigs. [shovill] Assembly is 1251, estimated genome size was 1188 (+5.30%) [shovill] Using genome graph file 'spades/assembly_graph_with_scaffolds.gfa' => 'contigs.gfa' [shovill] Walltime used: 1 min 40 sec [shovill] Results in: /corral4/main/jobs/044/273/44273377/working/out [shovill] Final assembly graph: /corral4/main/jobs/044/273/44273377/working/out/contigs.gfa [shovill] Final assembly contigs: /corral4/main/jobs/044/273/44273377/working/out/contigs.fa [shovill] It contains 1 (min=75) contigs totalling 1251 bp. [shovill] Wishing you a life free of misassemblies. [shovill] Done. ``` **Standard Output:** * ```console [kmc] ** [kmc] Stage 1: 0% Stage 1: 100% [kmc] Stage 2: 0% Stage 2: 84% Stage 2: 90% Stage 2: 94% Stage 2: 96% Stage 2: 98% Stage 2: 99% Stage 2: 100% [kmc] [kmc] 1st stage: 4.26127s [kmc] 2nd stage: 1.75349s [kmc] 3rd stage: 0.099813s [kmc] Total : 6.11457s [kmc] Tmp size : 0MB [kmc] Tmp size strict memory : 0MB [kmc] Tmp total: 0MB [kmc] [kmc] Stats: [kmc] No. of k-mers below min. threshold : 34495 [kmc] No. of k-mers above max. threshold : 0 [kmc] No. of unique k-mers : 35683 [kmc] No. of unique counted k-mers : 1188 [kmc] Total no. of k-mers : 130000 [kmc] Total no. of reads : 1000 [kmc] Total no. of super-k-mers : 18576 [lighter] [2022-06-30 18:21:48] =============Start==================== [lighter] [2022-06-30 18:21:48] Scanning the input files to infer alpha(sampling rate) [lighter] [2022-06-30 18:21:48] Average coverage is 103.535 and alpha is 0.068 [lighter] [2022-06-30 18:21:48] Bad quality threshold is "1" [lighter] [2022-06-30 18:21:48] Finish sampling kmers [lighter] [2022-06-30 18:21:48] Bloom filter A's false positive rate: 0.264464 [lighter] [2022-06-30 18:21:48] Finish storing trusted kmers [lighter] [2022-06-30 18:21:49] Finish error correction [lighter] Processed 820 reads: [lighter] 48 are error-free [lighter] Corrected 1731 bases(2.242228 corrections for reads with errors) [lighter] Trimmed 0 reads with average trimmed bases 0.000000 [lighter] Discard 0 reads [FLASH] Starting FLASH v1.2.11 [FLASH] Fast Length Adjustment of SHort reads [FLASH] [FLASH] Input files: [FLASH] R1.cor.fq.gz [FLASH] R2.cor.fq.gz [FLASH] [FLASH] Output files: [FLASH] ./flash.extendedFrags.fastq.gz [FLASH] ./flash.notCombined_1.fastq.gz [FLASH] ./flash.notCombined_2.fastq.gz [FLASH] ./flash.hist [FLASH] ./flash.histogram [FLASH] [FLASH] Parameters: [FLASH] Min overlap: 20 [FLASH] Max overlap: 150 [FLASH] Max mismatch density: 0.250000 [FLASH] Allow "outie" pairs: false [FLASH] Cap mismatch quals: false [FLASH] Combiner threads: 6 [FLASH] Input format: FASTQ, phred_offset=33 [FLASH] Output format: FASTQ, phred_offset=33, gzip [FLASH] [FLASH] Starting reader and writer threads [FLASH] Starting 6 combiner threads [FLASH] Processed 410 read pairs [FLASH] [FLASH] Read combination statistics: [FLASH] Total pairs: 410 [FLASH] Combined pairs: 387 [FLASH] Uncombined pairs: 23 [FLASH] Percent combined: 94.39% [FLASH] [FLASH] Writing histogram files. [FLASH] [FLASH] FLASH v1.2.11 complete! [FLASH] 0.088 seconds elapsed [spades] Command line: /usr/local/bin/spades.py -1 /corral4/main/jobs/044/273/44273377/working/out/flash.notCombined_1.fastq.gz -2 /corral4/main/jobs/044/273/44273377/working/out/flash.notCombined_2.fastq.gz --isolate --threads 6 --memory 29 -o /corral4/main/jobs/044/273/44273377/working/out/spades --tmp-dir /corral4/main/jobs/044/273/44273377/_job_tmp -k 31,51,71,91,111 --merged /corral4/main/jobs/044/273/44273377/working/out/flash.extendedFrags.fastq.gz [spades] [spades] System information: [spades] SPAdes version: 3.14.1 [spades] Python version: 3.8.8 [spades] OS: Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-glibc2.10 [spades] [spades] Output dir: /corral4/main/jobs/044/273/44273377/working/out/spades [spades] Mode: ONLY assembling (without read error correction) [spades] Debug mode is turned OFF [spades] [spades] Dataset parameters: [spades] Isolate mode [spades] Reads: [spades] Library number: 1, library type: paired-end [spades] orientation: fr [spades] left reads: ['/corral4/main/jobs/044/273/44273377/working/out/flash.notCombined_1.fastq.gz'] [spades] right reads: ['/corral4/main/jobs/044/273/44273377/working/out/flash.notCombined_2.fastq.gz'] [spades] interlaced reads: not specified [spades] single reads: not specified [spades] merged reads: ['/corral4/main/jobs/044/273/44273377/working/out/flash.extendedFrags.fastq.gz'] [spades] Assembly parameters: [spades] k: [31, 51, 71, 91, 111] [spades] Repeat resolution is enabled [spades] Mismatch careful mode is turned OFF [spades] MismatchCorrector will be SKIPPED [spades] Coverage cutoff is turned OFF [spades] Other parameters: [spades] Dir for temp files: /corral4/main/jobs/044/273/44273377/_job_tmp [spades] Threads: 6 [spades] Memory limit (in Gb): 29 [spades] [spades] [spades] ======= SPAdes pipeline started. Log can be found here: /corral4/main/jobs/044/273/44273377/working/out/spades/spades.log [spades] [spades] /corral4/main/jobs/044/273/44273377/working/out/flash.notCombined_1.fastq.gz: max reads length: 150 [spades] /corral4/main/jobs/044/273/44273377/working/out/flash.notCombined_2.fastq.gz: max reads length: 150 [spades] Files with merged reads were ignored. [spades] [spades] Reads length: 150 [spades] [spades] [spades] ===== Before start started. [spades] [spades] [spades] ===== Assembling started. [spades] [spades] [spades] ===== K31 started. [spades] [spades] [spades] == Running: /usr/local/bin/spades-core /corral4/main/jobs/044/273/44273377/working/out/spades/K31/configs/config.info /corral4/main/jobs/044/273/44273377/working/out/spades/K31/configs/isolate_mode.info [spades] [spades] WARNING: Try to use logger before create one. Level=INFO. Message=Additional contigs is tmp_contigs.fasta [spades] 0:00:00.000 4M / 11M INFO General (main.cpp : 75) Loaded config from /corral4/main/jobs/044/273/44273377/working/out/spades/K31/configs/config.info [spades] 0:00:00.000 4M / 11M INFO General (main.cpp : 75) Loaded config from /corral4/main/jobs/044/273/44273377/working/out/spades/K31/configs/isolate_mode.info [spades] 0:00:00.000 4M / 11M INFO General (memory_limit.cpp : 49) Memory limit set to 29 Gb [spades] 0:00:00.000 4M / 11M INFO General (main.cpp : 85) Starting SPAdes, built from N/A, git revision N/A [spades] 0:00:00.000 4M / 11M INFO General (main.cpp : 86) Maximum k-mer length: 128 [spades] 0:00:00.000 4M / 11M INFO General (main.cpp : 87) Assembling dataset (/corral4/main/jobs/044/273/44273377/working/out/spades/dataset.info) with K=31 [spades] 0:00:00.000 4M / 11M INFO General (main.cpp : 88) Maximum # of threads to use (adjusted due to OMP capabilities): 6 [spades] 0:00:00.000 4M / 11M INFO General (pipeline.cpp : 194) SPAdes started [spades] 0:00:00.000 4M / 11M INFO General (pipeline.cpp : 201) Starting from stage: read_conversion [spades] 0:00:00.000 4M / 11M INFO General (pipeline.cpp : 207) Two-step RR enabled: 0 [spades] 0:00:00.000 4M / 11M INFO StageManager (stage.cpp : 166) STAGE == Binary Read Conversion [spades] 0:00:00.007 4M / 11M INFO General (read_converter.cpp : 72) Converting reads to binary format for library #0 (takes a while) [spades] 0:00:00.007 4M / 11M INFO General (read_converter.cpp : 73) Converting paired reads [spades] 0:00:00.044 68M / 68M INFO General (binary_converter.cpp : 111) 23 reads written [spades] 0:00:00.044 44M / 44M INFO General (read_converter.cpp : 81) Converting single reads [spades] 0:00:00.051 54M / 54M INFO General (binary_converter.cpp : 111) 0 reads written [spades] 0:00:00.051 54M / 54M INFO General (read_converter.cpp : 87) Converting merged reads [spades] 0:00:00.065 75M / 75M INFO General (binary_converter.cpp : 111) 387 reads written [spades] 0:00:00.119 15M / 15M INFO StageManager (stage.cpp : 166) STAGE == de Bruijn graph construction [spades] 0:00:00.169 15M / 15M INFO General (construction.cpp : 150) Max read length 280 [spades] 0:00:00.169 15M / 15M INFO General (construction.cpp : 153) Max read length without merged 150 [spades] 0:00:00.169 15M / 15M INFO General (construction.cpp : 156) Average read length 193.032 [spades] 0:00:00.169 15M / 15M INFO General (stage.cpp : 113) PROCEDURE == k+1-mer counting [spades] 0:00:00.184 15M / 15M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 36 files using 6 threads. This might take a while. [spades] 0:00:00.193 15M / 15M INFO General (file_limit.hpp : 32) Open file limit set to 131072 [spades] 0:00:00.193 15M / 15M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.61105 Gb [spades] 0:00:00.193 15M / 15M INFO General (kmer_splitters.hpp : 97) Using cell size of 1864135 [spades] 0:00:01.020 23M / 23M INFO General (kmer_splitters.hpp : 293) Used 866 reads [spades] 0:00:01.020 23M / 23M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. [spades] 0:00:02.103 23M / 23M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 7283 kmers in total. [spades] 0:00:02.103 23M / 23M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. [spades] 0:00:02.527 23M / 23M INFO General (stage.cpp : 113) PROCEDURE == Extension index construction [spades] 0:00:02.538 23M / 23M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index [spades] 0:00:02.538 23M / 23M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 96 files using 6 threads. This might take a while. [spades] 0:00:02.547 23M / 23M INFO General (file_limit.hpp : 32) Open file limit set to 131072 [spades] 0:00:02.547 23M / 23M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.61092 Gb [spades] 0:00:02.547 23M / 23M INFO General (kmer_splitters.hpp : 97) Using cell size of 699050 [spades] 0:00:05.443 4G / 4G INFO General (kmer_splitters.hpp : 364) Processed 7283 kmers [spades] 0:00:05.443 4G / 4G INFO General (kmer_splitters.hpp : 369) Used 7283 kmers. [spades] 0:00:05.452 129M / 129M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. [spades] 0:00:08.507 129M / 129M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 7222 kmers in total. [spades] 0:00:08.508 129M / 129M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. [spades] 0:00:09.293 118M / 118M INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices [spades] 0:00:09.377 119M / 119M INFO General (kmer_index_builder.hpp : 150) Merging final buckets. [spades] 0:00:09.497 119M / 119M INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 12384 bytes occupied (13.7181 bits per kmer). [spades] 0:00:09.497 119M / 119M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers [spades] 0:00:09.517 119M / 119M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. [spades] 0:00:09.519 119M / 119M INFO General (stage.cpp : 113) PROCEDURE == Early tip clipping [spades] 0:00:09.520 119M / 119M INFO General (construction.cpp : 293) Early tip clipper length bound set as (RL - K) [spades] 0:00:09.520 119M / 119M INFO Early tip clipping (early_simplification.hpp : 28) Early tip clipping [spades] 0:00:09.526 119M / 119M INFO Early tip clipping (early_simplification.hpp : 63) #tipped junctions: 96 [spades] 0:00:09.526 119M / 119M INFO Early tip clipping (early_simplification.hpp : 74) Clipped tips: 97 [spades] 0:00:09.527 119M / 119M INFO Early tip clipping (early_simplification.hpp : 30) 2642 32-mers were removed by early tip clipper [spades] 0:00:09.527 119M / 119M INFO General (stage.cpp : 113) PROCEDURE == Condensing graph [spades] 0:00:09.535 119M / 119M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths [spades] 0:00:09.538 119M / 119M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 186 sequences extracted [spades] 0:00:09.539 119M / 119M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 309) Collecting perfect loops [spades] 0:00:09.552 119M / 119M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 342) Collecting perfect loops finished. 0 loops collected [spades] 0:00:09.552 119M / 119M INFO General (stage.cpp : 113) PROCEDURE == Filling coverage indices (PHM) [spades] 0:00:09.553 119M / 119M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index [spades] 0:00:09.553 119M / 119M INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices [spades] 0:00:09.660 119M / 119M INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 6688 bytes occupied (7.34642 bits per kmer). [spades] 0:00:09.661 119M / 119M INFO General (construction.cpp : 429) Collecting k-mer coverage information from reads, this takes a while. [spades] 0:00:09.702 119M / 119M INFO General (construction.cpp : 549) Filling coverage and flanking coverage from PHM [spades] 0:00:09.745 119M / 119M INFO StageManager (stage.cpp : 166) STAGE == EC Threshold Finding [spades] 0:00:09.745 119M / 119M INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 [spades] 0:00:09.746 119M / 119M INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 60 [spades] 0:00:09.746 119M / 119M INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 60. Coverage mad: 7.413 [spades] 0:00:09.746 119M / 119M INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model [spades] 0:00:09.762 119M / 119M INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 [spades] 0:00:09.800 119M / 119M INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 [spades] 0:00:09.870 113M / 113M INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 [spades] 0:00:09.950 113M / 113M INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 [spades] 0:00:09.983 113M / 113M INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 56.9644. Fitted coverage std. dev: 9.10691 [spades] 0:00:09.983 113M / 113M INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 1 [spades] 0:00:09.983 113M / 113M INFO General (kmer_coverage_model. .. : 166) STAGE == Contig Output [spades] 0:00:20.850 23M / 23M INFO General (contig_output.hpp : 21) Outputting contigs to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/before_rr.fasta [spades] 0:00:20.856 23M / 23M INFO General (contig_output_stage.cpp : 146) Writing GFA graph to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/assembly_graph_after_simplification.gfa [spades] 0:00:20.857 23M / 23M INFO StageManager (stage.cpp : 166) STAGE == Paired Information Counting [spades] 0:00:20.857 23M / 23M INFO General (graph_pack.hpp : 113) Normalizing k-mer map. Total 1220 kmers to process [spades] 0:00:20.858 23M / 23M INFO General (graph_pack.hpp : 115) Normalizing done [spades] 0:00:20.858 23M / 23M INFO General (pair_info_count.cpp : 322) Min edge length for estimation: 1140 [spades] 0:00:20.858 23M / 23M INFO General (pair_info_count.cpp : 333) Estimating insert size for library #0 [spades] 0:00:20.858 23M / 23M INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) [spades] 0:00:20.993 135M / 135M INFO General (pair_info_count.cpp : 39) Selecting usual mapper [spades] 0:00:21.138 135M / 135M INFO General (sequence_mapper_notifier.h: 94) Total 410 reads processed [spades] 0:00:21.263 135M / 135M INFO General (pair_info_count.cpp : 208) Edge pairs: 2 [spades] 0:00:21.264 135M / 135M INFO General (pair_info_count.cpp : 210) 334 paired reads (81.4634% of all) aligned to long edges [spades] 0:00:21.276 23M / 125M INFO General (pair_info_count.cpp : 352) Insert size = 201.347, deviation = 42.1646, left quantile = 150, right quantile = 261, read length = 150 [spades] 0:00:21.276 23M / 125M INFO General (pair_info_count.cpp : 373) Filtering data for library #0 [spades] 0:00:21.316 23M / 125M INFO General (pair_info_count.cpp : 39) Selecting usual mapper [spades] 0:00:21.319 23M / 125M INFO General (sequence_mapper_notifier.h: 94) Total 410 reads processed [spades] 0:00:21.319 23M / 125M INFO General (pair_info_count.cpp : 385) Mapping library #0 [spades] 0:00:21.320 23M / 125M INFO General (pair_info_count.cpp : 387) Mapping paired reads (takes a while) [spades] 0:00:21.320 23M / 125M INFO General (pair_info_count.cpp : 285) Left insert size quantile 150, right insert size quantile 261, filtering threshold 2, rounding threshold 0 [spades] 0:00:21.351 32M / 125M INFO General (pair_info_count.cpp : 39) Selecting usual mapper [spades] 0:00:21.355 32M / 125M INFO General (sequence_mapper_notifier.h: 94) Total 410 reads processed [spades] 0:00:21.360 23M / 125M INFO StageManager (stage.cpp : 166) STAGE == Distance Estimation [spades] 0:00:21.361 23M / 125M INFO General (distance_estimation.cpp : 174) Processing library #0 [spades] 0:00:21.361 23M / 125M INFO General (distance_estimation.cpp : 150) Weight Filter Done [spades] 0:00:21.361 23M / 125M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator [spades] 0:00:21.361 23M / 125M INFO General (distance_estimation.cpp : 35) Filtering info [spades] 0:00:21.362 23M / 125M INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2 [spades] 0:00:21.362 23M / 125M INFO General (pair_info_filters.hpp : 263) Done filtering [spades] 0:00:21.362 23M / 125M INFO General (distance_estimation.cpp : 157) Refining clustered pair information [spades] 0:00:21.362 23M / 125M INFO General (distance_estimation.cpp : 159) The refining of clustered pair information has been finished [spades] 0:00:21.362 23M / 125M INFO General (distance_estimation.cpp : 161) Improving paired information [spades] 0:00:21.363 23M / 125M INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 0; contradictional = 0 [spades] 0:00:21.364 23M / 125M INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 0; contradictional = 0 [spades] 0:00:21.364 23M / 125M INFO General (distance_estimation.cpp : 104) Filling scaffolding index [spades] 0:00:21.364 23M / 125M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator [spades] 0:00:21.364 23M / 125M INFO General (distance_estimation.cpp : 35) Filtering info [spades] 0:00:21.365 23M / 125M INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2 [spades] 0:00:21.365 23M / 125M INFO General (pair_info_filters.hpp : 263) Done filtering [spades] 0:00:21.365 23M / 125M INFO General (distance_estimation.cpp : 183) Clearing raw paired index [spades] 0:00:21.365 23M / 125M INFO StageManager (stage.cpp : 166) STAGE == Repeat Resolving [spades] 0:00:21.365 23M / 125M INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving [spades] 0:00:21.366 23M / 125M INFO General (launcher.cpp : 538) ExSPAnder repeat resolving tool started [spades] 0:00:21.373 23M / 125M INFO General (launcher.cpp : 404) Creating main extenders, unique edge length = 2000 [spades] 0:00:21.373 23M / 125M INFO General (extenders_logic.cpp : 311) Estimated coverage of library #0 is 25.1649 [spades] 0:00:21.374 23M / 125M INFO General (extenders_logic.cpp : 311) Estimated coverage of library #0 is 25.1649 [spades] 0:00:21.374 23M / 125M INFO General (extenders_logic.cpp : 519) Using 1 paired-end library [spades] 0:00:21.374 23M / 125M INFO General (extenders_logic.cpp : 520) Using 1 paired-end scaffolding library [spades] 0:00:21.374 23M / 125M INFO General (extenders_logic.cpp : 521) Using 0 single read libraries [spades] 0:00:21.374 23M / 125M INFO General (launcher.cpp : 432) Total number of extenders is 3 [spades] 0:00:21.375 23M / 125M INFO General (launcher.cpp : 244) Finalizing paths [spades] 0:00:21.375 23M / 125M INFO General (launcher.cpp : 246) Deduplicating paths [spades] 0:00:21.375 23M / 125M INFO General (launcher.cpp : 250) Paths deduplicated [spades] 0:00:21.375 23M / 125M INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps [spades] 0:00:21.376 23M / 125M INFO PEResolver (pe_resolver.hpp : 298) Sorting paths [spades] 0:00:21.376 23M / 125M INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps [spades] 0:00:21.376 23M / 125M INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps [spades] 0:00:21.376 23M / 125M INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps [spades] 0:00:21.376 23M / 125M INFO PEResolver (pe_resolver.hpp : 308) Splitting paths [spades] 0:00:21.377 23M / 125M INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths [spades] 0:00:21.377 23M / 125M INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed [spades] 0:00:21.377 23M / 125M INFO General (launcher.cpp : 267) Paths finalized [spades] 0:00:21.377 23M / 125M INFO General (launcher.cpp : 439) Closing gaps in paths [spades] 0:00:21.377 23M / 125M INFO General (launcher.cpp : 467) Gap closing completed [spades] 0:00:21.378 23M / 125M INFO General (launcher.cpp : 296) Traversing tandem repeats [spades] 0:00:21.378 23M / 125M INFO General (launcher.cpp : 306) Traversed 0 loops [spades] 0:00:21.378 23M / 125M INFO General (launcher.cpp : 244) Finalizing paths [spades] 0:00:21.378 23M / 125M INFO General (launcher.cpp : 246) Deduplicating paths [spades] 0:00:21.378 23M / 125M INFO General (launcher.cpp : 250) Paths deduplicated [spades] 0:00:21.379 23M / 125M INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps [spades] 0:00:21.379 23M / 125M INFO PEResolver (pe_resolver.hpp : 298) Sorting paths [spades] 0:00:21.379 23M / 125M INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps [spades] 0:00:21.379 23M / 125M INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps [spades] 0:00:21.379 23M / 125M INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps [spades] 0:00:21.379 23M / 125M INFO PEResolver (pe_resolver.hpp : 308) Splitting paths [spades] 0:00:21.380 23M / 125M INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths [spades] 0:00:21.380 23M / 125M INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed [spades] 0:00:21.380 23M / 125M INFO General (launcher.cpp : 267) Paths finalized [spades] 0:00:21.380 23M / 125M INFO General (launcher.cpp : 596) ExSPAnder repeat resolving tool finished [spades] 0:00:21.380 23M / 125M INFO StageManager (stage.cpp : 166) STAGE == Contig Output [spades] 0:00:21.381 23M / 125M INFO General (contig_output.hpp : 21) Outputting contigs to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/before_rr.fasta [spades] 0:00:21.393 23M / 125M INFO General (contig_output_stage.cpp : 146) Writing GFA graph to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/assembly_graph_with_scaffolds.gfa [spades] 0:00:21.394 23M / 125M INFO General (contig_output_stage.cpp : 160) Outputting FastG graph to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/assembly_graph.fastg [spades] 0:00:21.399 23M / 125M INFO General (contig_output_stage.cpp : 190) Breaking scaffolds [spades] 0:00:21.399 23M / 125M INFO General (contig_output_stage.cpp : 95) Outputting contigs to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/final_contigs.fasta [spades] 0:00:21.402 23M / 125M INFO General (contig_output_stage.cpp : 101) Outputting FastG paths to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/final_contigs.paths [spades] 0:00:21.405 23M / 125M INFO General (contig_output_stage.cpp : 95) Outputting contigs to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/scaffolds.fasta [spades] 0:00:21.409 23M / 125M INFO General (contig_output_stage.cpp : 101) Outputting FastG paths to /corral4/main/jobs/044/273/44273377/working/out/spades/K111/scaffolds.paths [spades] 0:00:21.412 23M / 125M INFO General (contig_output_stage.cpp : 108) Populating GFA with scaffold paths [spades] 0:00:21.417 23M / 125M INFO General (pipeline.cpp : 259) SPAdes finished [spades] 0:00:21.422 23M / 125M INFO General (main.cpp : 107) Assembling time: 0 hours 0 minutes 21 seconds [spades] [spades] ===== K111 finished. [spades] [spades] [spades] ===== Copy files started. [spades] [spades] [spades] == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/copy_files.py /corral4/main/jobs/044/273/44273377/working/out/spades/K111/before_rr.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/before_rr.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/K111/assembly_graph_after_simplification.gfa /corral4/main/jobs/044/273/44273377/working/out/spades/assembly_graph_after_simplification.gfa /corral4/main/jobs/044/273/44273377/working/out/spades/K111/final_contigs.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/contigs.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/K111/first_pe_contigs.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/first_pe_contigs.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/K111/strain_graph.gfa /corral4/main/jobs/044/273/44273377/working/out/spades/strain_graph.gfa /corral4/main/jobs/044/273/44273377/working/out/spades/K111/scaffolds.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/scaffolds.fasta /corral4/main/jobs/044/273/44273377/working/out/spades/K111/scaffolds.paths /corral4/main/jobs/044/273/44273377/working/out/spades/scaffolds.paths /corral4/main/jobs/044/273/44273377/working/out/spades/K111/assembly_graph_with_scaffolds.gfa /corral4/main/jobs/044/273/44273377/working/out/spades/assembly_graph_with_scaffolds.gfa /corral4/main/jobs/044/273/44273377/working/out/spades/K111/assembly_graph.fastg /corral4/main/jobs/044/273/44273377/working/out/spades/assembly_graph.fastg /corral4/main/jobs/044/273/44273377/working/out/spades/K111/final_contigs.paths /corral4/main/jobs/044/273/44273377/working/out/spades/contigs.paths [spades] [spades] [spades] ===== Copy files finished. [spades] [spades] [spades] ===== Assembling finished. [spades] [spades] [spades] ===== Breaking scaffolds started. [spades] [spades] [spades] == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/breaking_scaffolds_script.py --result_scaffolds_filename /corral4/main/jobs/044/273/44273377/working/out/spades/scaffolds.fasta --misc_dir /corral4/main/jobs/044/273/44273377/working/out/spades/misc --threshold_for_breaking_scaffolds 3 [spades] [spades] [spades] ===== Breaking scaffolds finished. [spades] [spades] [spades] ===== Terminate started. [spades] [spades] [spades] ===== Terminate finished. [spades] [spades] * Assembled contigs are in /corral4/main/jobs/044/273/44273377/working/out/spades/contigs.fasta [spades] * Assembled scaffolds are in /corral4/main/jobs/044/273/44273377/working/out/spades/scaffolds.fasta [spades] * Paths in the assembly graph corresponding to the contigs are in /corral4/main/jobs/044/273/44273377/working/out/spades/contigs.paths [spades] * Paths in the assembly graph corresponding to the scaffolds are in /corral4/main/jobs/044/273/44273377/working/out/spades/scaffolds.paths [spades] * Assembly graph is in /corral4/main/jobs/044/273/44273377/working/out/spades/assembly_graph.fastg [spades] * Assembly graph in GFA format is in /corral4/main/jobs/044/273/44273377/working/out/spades/assembly_graph_with_scaffolds.gfa [spades] [spades] ======= SPAdes pipeline finished. [spades] [spades] SPAdes log can be found here: /corral4/main/jobs/044/273/44273377/working/out/spades/spades.log [spades] [spades] Thank you for using SPAdes! ``` **Job Parameters:** * | Job parameter | Parameter value | | ------------- | --------------- | | library | ` {"R1": {"values": [{"id": 99730717, "src": "hda"}]}, "R2": {"values": [{"id": 99730731, "src": "hda"}]}, "__current_case__": 0, "lib_type": "paired"} ` | | trim | ` "false" ` | | log | ` "true" ` | | assembler | ` "spades" ` | | adv | ` {"depth": "100", "gsize": "", "kmers": "", "mincov": "2", "minlen": "0", "namefmt": "contig%05d", "nocorr": "true", "opts": ""} ` | | \_\_job\_resource | ` {"__current_case__": 0, "__job_resource__select": "no"} ` | | chromInfo | ` "/cvmfs/data.galaxyproject.org/managed/len/ucsc/?.len" ` | | dbkey | ` "?" ` | | \_\_input\_ext | ` "fastqsanger" ` |

• ✅ toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill (Test #2)

  **Command Line:** * ```console ``` **Exit Code:** * ```console 0 ``` **Standard Error:** * ```console [shovill] Hello g2main [shovill] You ran: /usr/local/bin/shovill --outdir out --cpus 6 --ram 30 --R1 fastq_r1.fastqsanger --R2 fastq_r2.fastqsanger --trim --namefmt contig%03d --depth 0 --minlen 0 --mincov 0 --assembler spades [shovill] This is shovill 1.1.0 [shovill] Written by Torsten Seemann [shovill] Homepage is https://github.com/tseemann/shovill [shovill] Operating system is linux [shovill] Perl version is v5.26.2 [shovill] Machine has 32 CPU cores and 125.71 GB RAM [shovill] Using bwa - /usr/local/bin/bwa | Version: 0.7.17-r1188 [shovill] Using flash - /usr/local/bin/flash | FLASH v1.2.11 [shovill] Using java - /usr/local/bin/java | openjdk version "11.0.1" 2018-10-16 LTS [shovill] Using kmc - /usr/local/bin/kmc | K-Mer Counter (KMC) ver. 3.1.1 (2019-05-19) [shovill] Using lighter - /usr/local/bin/lighter | Lighter v1.1.2 [shovill] Using megahit - /usr/local/bin/megahit | MEGAHIT v1.2.9 [shovill] Using megahit_toolkit - /usr/local/bin/megahit_toolkit | v1.2.9 [shovill] Using pigz - /usr/local/bin/pigz | pigz 2.6 [shovill] Using pilon - /usr/local/bin/pilon | Pilon version 1.23 Mon Nov 26 16:04:05 2018 -0500 [shovill] Using samclip - /usr/local/bin/samclip | samclip 0.4.0 [shovill] Using samtools - /usr/local/bin/samtools | Version: 1.12 (using htslib 1.12) [shovill] Using seqtk - /usr/local/bin/seqtk | Version: 1.3-r106 [shovill] Using skesa - /usr/local/bin/skesa | SKESA 2.4.0 [shovill] Using spades.py - /usr/local/bin/spades.py | SPAdes genome assembler v3.14.1 [shovill] Using trimmomatic - /usr/local/bin/trimmomatic | 0.39 [shovill] Using velvetg - /usr/local/bin/velvetg | Version 1.2.10 [shovill] Using velveth - /usr/local/bin/velveth | Version 1.2.10 [shovill] Found spades version: 003014000 [shovill] Will use spades 003014000 options: --isolate and --merged [shovill] Using tempdir: /corral4/main/jobs/044/273/44273376/_job_tmp [shovill] Changing into folder: /corral4/main/jobs/044/273/44273376/working/out [shovill] Collecting raw read statistics with 'seqtk' [shovill] Running: seqtk fqchk -q3 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat >/corral4/main/jobs/044/273/44273376/_job_tmp/tZ02cAbGwP 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Read stats: max_len = 150 [shovill] Read stats: avg_len = 150 [shovill] Read stats: min_len = 150 [shovill] Read stats: total_bp = 300000 [shovill] Estimating genome size by counting unqiue 21-mers > frequency 10 [shovill] Running: kmc -sm -m15 -t6 -k21 -ci10 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat /corral4/main/jobs/044/273/44273376/_job_tmp/wAQlbSymah/kmc /corral4/main/jobs/044/273/44273376/_job_tmp/wAQlbSymah 2>&1 | sed 's/^/[kmc] /' | tee -a shovill.log [shovill] Using genome size 1188 bp [shovill] Estimated sequencing depth: 252 x [shovill] No read depth reduction requested or necessary. [shovill] Appending -Xmx30g to _JAVA_OPTIONS [shovill] Trimming reads [shovill] Running: trimmomatic PE -threads 6 -phred33 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat \/corral4\/main\/objects\/3\/6\/e\/dataset_36e11e53\-e2b5\-46ec\-bb32\-f57f5aa02e03\.dat R1.fq.gz /dev/null R2.fq.gz /dev/null ILLUMINACLIP:/usr/local/db/trimmomatic.fa:1:30:11 LEADING:3 TRAILING:3 MINLEN:30 TOPHRED33 2>&1 | sed 's/^/[trimmomatic] /' | tee -a shovill.log [shovill] Average read length looks like 150 bp [shovill] Automatically setting --minlen to 75 [shovill] Setting k-mer range to (31 .. 112) [shovill] Estimated K-mers: 31 51 71 91 111 [kn=5, ks=20, kmin=31, kmax=112] [shovill] Using kmers: 31,51,71,91,111 [shovill] Correcting reads with 'Lighter' [shovill] Running: lighter -od . -r R1.fq.gz -r R2.fq.gz -K 32 1188 -t 6 -maxcor 1 2>&1 | sed 's/^/[lighter] /' | tee -a shovill.log [shovill] Overlapping/stitching PE reads with 'FLASH' [shovill] Running: flash -m 20 -M 150 -d . -o flash -z -t 6 R1.cor.fq.gz R2.cor.fq.gz 2>&1 | sed 's/^//' | tee -a shovill.log [shovill] Assembling reads with 'spades' [shovill] Running: spades.py -1 flash.notCombined_1.fastq.gz -2 flash.notCombined_2.fastq.gz --isolate --threads 6 --memory 30 -o spades --tmp-dir /corral4/main/jobs/044/273/44273376/_job_tmp -k 31,51,71,91,111 --merged flash.extendedFrags.fastq.gz 2>&1 | sed 's/^/[spades] /' | tee -a shovill.log [shovill] Checking for assembly errors in spades.fasta [shovill] Running: bwa index spades.fasta 2>&1 | sed 's/^/[bwa-index] /' | tee -a shovill.log [shovill] Running: samtools faidx spades.fasta 2>&1 | sed 's/^/[faidx] /' | tee -a shovill.log [shovill] Running: (bwa mem -v 3 -x intractg -t 6 spades.fasta R1.fq.gz R2.fq.gz | samclip --ref spades.fasta.fai | samtools sort --threads 1 -m 15360m --reference spades.fasta -T /corral4/main/jobs/044/273/44273376/_job_tmp -o shovill.bam) 2>&1 | sed 's/^/[bwa+samtools-sort] /' | tee -a shovill.log [shovill] Running: samtools index shovill.bam 2>&1 | sed 's/^/[samtools-index] /' | tee -a shovill.log [shovill] Correcting errors in spades.fasta [shovill] Running: pilon --genome spades.fasta --frags shovill.bam --minmq 60 --minqual 3 --fix bases --output pilon --threads 6 --changes --mindepth 0.25 2>&1 | sed 's/^/[pilon] /' | tee -a shovill.log [shovill] Repaired 0 contigs from spades.fasta at 0 positions. [shovill] Assembly is 1254, estimated genome size was 1188 (+5.56%) [shovill] Using genome graph file 'spades/assembly_graph_with_scaffolds.gfa' => 'contigs.gfa' [shovill] Walltime used: 13 min 43 sec [shovill] Results in: /corral4/main/jobs/044/273/44273376/working/out [shovill] Final assembly graph: /corral4/main/jobs/044/273/44273376/working/out/contigs.gfa [shovill] Final assembly contigs: /corral4/main/jobs/044/273/44273376/working/out/contigs.fa [shovill] It contains 1 (min=75) contigs totalling 1254 bp. [shovill] Wishing you a life free of misassemblies. [shovill] Done. ``` **Standard Output:** * ```console [kmc] ** [kmc] Stage 1: 0% Stage 1: 100% [kmc] Stage 2: 0% Stage 2: 84% Stage 2: 90% Stage 2: 94% Stage 2: 96% Stage 2: 98% Stage 2: 99% Stage 2: 100% [kmc] [kmc] 1st stage: 30.6954s [kmc] 2nd stage: 13.9423s [kmc] 3rd stage: 0.234068s [kmc] Total : 44.8717s [kmc] Tmp size : 0MB [kmc] Tmp size strict memory : 0MB [kmc] Tmp total: 0MB [kmc] [kmc] Stats: [kmc] No. of k-mers below min. threshold : 34495 [kmc] No. of k-mers above max. threshold : 0 [kmc] No. of unique k-mers : 35683 [kmc] No. of unique counted k-mers : 1188 [kmc] Total no. of k-mers : 130000 [kmc] Total no. of reads : 1000 [kmc] Total no. of super-k-mers : 18576 [trimmomatic] Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/corral4/main/jobs/044/273/44273376/_job_tmp -Xmx28g -Xms256m -Xmx30g [trimmomatic] TrimmomaticPE: Started with arguments: [trimmomatic] -threads 6 -phred33 /corral4/main/objects/1/6/0/dataset_160df692-9804-452e-b575-c79f5910295c.dat /corral4/main/objects/3/6/e/dataset_36e11e53-e2b5-46ec-bb32-f57f5aa02e03.dat R1.fq.gz /dev/null R2.fq.gz /dev/null ILLUMINACLIP:/usr/local/db/trimmomatic.fa:1:30:11 LEADING:3 TRAILING:3 MINLEN:30 TOPHRED33 [trimmomatic] Using PrefixPair: 'AGATGTGTATAAGAGACAG' and 'AGATGTGTATAAGAGACAG' [trimmomatic] Using PrefixPair: 'TACACTCTTTCCCTACACGACGCTCTTCCGATCT' and 'GTGACTGGAGTTCAGACGTGTGCTCTTCCGATCT' [trimmomatic] Using Long Clipping Sequence: 'GTCTCGTGGGCTCGGAGATGTGTATAAGAGACAG' [trimmomatic] Using Long Clipping Sequence: 'TCGTCGGCAGCGTCAGATGTGTATAAGAGACAG' [trimmomatic] Using Long Clipping Sequence: 'AGATCGGAAGAGCTCGTATGCCGTCTTCTGCTTG' [trimmomatic] Using Long Clipping Sequence: 'AGATCGGAAGAGCGTCGTGTAGGGAAAGAGTGTA' [trimmomatic] Skipping duplicate Clipping Sequence: 'AGATCGGAAGAGCGTCGTGTAGGGAAAGAGTGTA' [trimmomatic] Using Long Clipping Sequence: 'AGATCGGAAGAGCGTCGTGTAGGGAAAGAGTGTAGATCTCGGTGGTCGCCGTATCATT' [trimmomatic] Using Long Clipping Sequence: 'AGATCGGAAGAGCGGTTCAGCAGGAATGCCGAG' [trimmomatic] Using Long Clipping Sequence: 'AGATCGGAAGAGCGGTTCAGCAGGAATGCCGAGACCGATCTCGTATGCCGTCTTCTGCTTG' [trimmomatic] Using Long Clipping Sequence: 'TTTTTTTTTTAATGATACGGCGACCACCGAGATCTACAC' [trimmomatic] Using Long Clipping Sequence: 'AGATCGGAAGAGCACACGTCTGAACTCCAGTCAC' [trimmomatic] Using Long Clipping Sequence: 'AGATCGGAAGAGCGTCGTGTAGGGAAAGAGTGT' [trimmomatic] Using Long Clipping Sequence: 'TTTTTTTTTTCAAGCAGAAGACGGCATACGA' [trimmomatic] Skipping duplicate Clipping Sequence: 'AGATCGGAAGAGCACACGTCTGAACTCCAGTCAC' [trimmomatic] Using Long Clipping Sequence: 'GTGACTGGAGTTCAGACGTGTGCTCTTCCGATCT' [trimmomatic] Using Long Clipping Sequence: 'TACACTCTTTCCCTACACGACGCTCTTCCGATCT' [trimmomatic] Using Long Clipping Sequence: 'CTGTCTCTTATACACATCTCCGAGCCCACGAGAC' [trimmomatic] Using Long Clipping Sequence: 'CAAGCAGAAGACGGCATACGAGATCGGTCTCGGCATTCCTGCTGAACCGCTCTTCCGATCT' [trimmomatic] Using Long Clipping Sequence: 'CTGTCTCTTATACACATCTGACGCTGCCGACGA' [trimmomatic] Using Long Clipping Sequence: 'AATGATACGGCGACCACCGAGATCTACACTCTTTCCCTACACGACGCTCTTCCGATCT' [trimmomatic] ILLUMINACLIP: Using 2 prefix pairs, 17 forward/reverse sequences, 0 forward only sequences, 0 reverse only sequences [trimmomatic] Input Read Pairs: 1000 Both Surviving: 1000 (100.00%) Forward Only Surviving: 0 (0.00%) Reverse Only Surviving: 0 (0.00%) Dropped: 0 (0.00%) [trimmomatic] TrimmomaticPE: Completed successfully [lighter] [2022-06-30 13:24:46] =============Start==================== [lighter] [2022-06-30 13:24:47] Scanning the input files to infer alpha(sampling rate) [lighter] [2022-06-30 13:24:47] Average coverage is 252.525 and alpha is 0.028 [lighter] [2022-06-30 13:24:47] Bad quality threshold is "1" [lighter] [2022-06-30 13:24:48] Finish sampling kmers [lighter] [2022-06-30 13:24:48] Bloom filter A's false positive rate: 0.258936 [lighter] [2022-06-30 13:24:48] Finish storing trusted kmers [lighter] [2022-06-30 13:24:48] Finish error correction [lighter] Processed 2000 reads: [lighter] 104 are error-free [lighter] Corrected 4376 bases(2.308017 corrections for reads with errors) [lighter] Trimmed 0 reads with average trimmed bases 0.000000 [lighter] Discard 0 reads [FLASH] Starting FLASH v1.2.11 [FLASH] Fast Length Adjustment of SHort reads [FLASH] [FLASH] Input files: [FLASH] R1.cor.fq.gz [FLASH] R2.cor.fq.gz [FLASH] [FLASH] Output files: [FLASH] ./flash.extendedFrags.fastq.gz [FLASH] ./flash.notCombined_1.fastq.gz [FLASH] ./flash.notCombined_2.fastq.gz [FLASH] ./flash.hist [FLASH] ./flash.histogram [FLASH] [FLASH] Parameters: [FLASH] Min overlap: 20 [FLASH] Max overlap: 150 [FLASH] Max mismatch density: 0.250000 [FLASH] Allow "outie" pairs: false [FLASH] Cap mismatch quals: false [FLASH] Combiner threads: 6 [FLASH] Input format: FASTQ, phred_offset=33 [FLASH] Output format: FASTQ, phred_offset=33, gzip [FLASH] [FLASH] Starting reader and writer threads [FLASH] Starting 6 combiner threads [FLASH] Processed 1000 read pairs [FLASH] [FLASH] Read combination statistics: [FLASH] Total pairs: 1000 [FLASH] Combined pairs: 946 [FLASH] Uncombined pairs: 54 [FLASH] Percent combined: 94.60% [FLASH] [FLASH] Writing histogram files. [FLASH] [FLASH] FLASH v1.2.11 complete! [FLASH] 0.448 seconds elapsed [spades] Command line: /usr/local/bin/spades.py -1 /corral4/main/jobs/044/273/44273376/working/out/flash.notCombined_1.fastq.gz -2 /corral4/main/jobs/044/273/44273376/working/out/flash.notCombined_2.fastq.gz --isolate --threads 6 --memory 30 -o /corral4/main/jobs/044/273/44273376/working/out/spades --tmp-dir /corral4/main/jobs/044/273/44273376/_job_tmp -k 31,51,71,91,111 --merged /corral4/main/jobs/044/273/44273376/working/out/flash.extendedFrags.fastq.gz [spades] [spades] System information: [spades] SPAdes version: 3.14.1 [spades] Python version: 3.8.8 [spades] OS: Linux-3.10.0-1062.18.1.el7.x86_64-x86_64-with-glibc2.10 [spades] [spades] Output dir: /corral4/main/jobs/044/273/44273376/working/out/spades [spades] Mode: ONLY assembling (without read error correction) [spades] Debug mode is turned OFF [spades] [spades] Dataset parameters: [spades] Isolate mode [spades] Reads: [spades] Library number: 1, library type: paired-end [spades] orientation: fr [spades] left reads: ['/corral4/main/jobs/044/273/44273376/working/out/flash.notCombined_1.fastq.gz'] [spades] right reads: ['/corral4/main/jobs/044/273/44273376/working/out/flash.notCombined_2.fastq.gz'] [spades] interlaced reads: not specified [spades] single reads: not specified [spades] merged reads: ['/corral4/main/jobs/044/273/44273376/working/out/flash.extendedFrags.fastq.gz'] [spades] Assembly parameters: [spades] k: [31, 51, 71, 91, 111] [spades] Repeat resolution is enabled [spades] Mismatch careful mode is turned OFF [spades] MismatchCorrector will be SKIPPED [spades] Coverage cutoff is turned OFF [spades] Other parameters: [spades] Dir for temp files: /corral4/main/jobs/044/273/44273376/_job_tmp [spades] Threads: 6 [spades] Memory limit (in Gb): 30 [spades] [spades] [spades] ======= SPAdes pipeline started. Log can be found here: /corral4/main/jobs/044/273/44273376/working/out/spades/spades.log [spades] [spades] /corral4/main/jobs/044/273/44273376/working/out/flash.notCombined_1.fastq.gz: max reads length: 150 [spades] /corral4/main/jobs/044/273/44273376/working/out/flash.notCombined_2.fastq.gz: max reads length: 150 [spades] Files with merged reads were ignored. [spades] [spades] Reads length: 150 [spades] [spades] [spades] ===== Before start started. [spades] [spades] [spades] ===== Assembling started. [spades] [spades] [spades] ===== K31 started. [spades] [spades] [spades] == Running: /usr/local/bin/spades-core /corral4/main/jobs/044/273/44273376/working/out/spades/K31/configs/config.info /corral4/main/jobs/044/273/44273376/working/out/spades/K31/configs/isolate_mode.info [spades] [spades] WARNING: Try to use logger before create one. Level=INFO. Message=Additional contigs is tmp_contigs.fasta [spades] 0:00:00.006 4M / 6M INFO General (main.cpp : 75) Loaded config from /corral4/main/jobs/044/273/44273376/working/out/spades/K31/configs/config.info [spades] 0:00:00.018 4M / 6M INFO General (main.cpp : 75) Loaded config from /corral4/main/jobs/044/273/44273376/working/out/spades/K31/configs/isolate_mode.info [spades] 0:00:00.029 4M / 6M INFO General (memory_limit.cpp : 49) Memory limit set to 30 Gb [spades] 0:00:00.029 4M / 6M INFO General (main.cpp : 85) Starting SPAdes, built from N/A, git revision N/A [spades] 0:00:00.029 4M / 6M INFO General (main.cpp : 86) Maximum k-mer length: 128 [spades] 0:00:00.029 4M / 6M INFO General (main.cpp : 87) Assembling dataset (/corral4/main/jobs/044/273/44273376/working/out/spades/dataset.info) with K=31 [spades] 0:00:00.029 4M / 6M INFO General (main.cpp : 88) Maximum # of threads to use (adjusted due to OMP capabilities): 6 [spades] 0:00:00.038 4M / 6M INFO General (pipeline.cpp : 194) SPAdes started [spades] 0:00:00.038 4M / 6M INFO General (pipeline.cpp : 201) Starting from stage: read_conversion [spades] 0:00:00.038 4M / 6M INFO General (pipeline.cpp : 207) Two-step RR enabled: 0 [spades] 0:00:00.059 4M / 6M INFO StageManager (stage.cpp : 166) STAGE == Binary Read Conversion [spades] 0:00:00.359 4M / 6M INFO General (read_converter.cpp : 72) Converting reads to binary format for library #0 (takes a while) [spades] 0:00:00.364 4M / 6M INFO General (read_converter.cpp : 73) Converting paired reads [spades] 0:00:00.698 68M / 68M INFO General (binary_converter.cpp : 111) 54 reads written [spades] 0:00:00.698 44M / 44M INFO General (read_converter.cpp : 81) Converting single reads [spades] 0:00:00.732 54M / 54M INFO General (binary_converter.cpp : 111) 0 reads written [spades] 0:00:00.732 54M / 54M INFO General (read_converter.cpp : 87) Converting merged reads [spades] 0:00:01.047 75M / 75M INFO General (binary_converter.cpp : 111) 946 reads written [spades] 0:00:01.281 15M / 15M INFO StageManager (stage.cpp : 166) STAGE == de Bruijn graph construction [spades] 0:00:02.843 15M / 15M INFO General (construction.cpp : 150) Max read length 280 [spades] 0:00:02.864 15M / 15M INFO General (construction.cpp : 153) Max read length without merged 150 [spades] 0:00:02.872 15M / 15M INFO General (construction.cpp : 156) Average read length 192.639 [spades] 0:00:02.880 15M / 15M INFO General (stage.cpp : 113) PROCEDURE == k+1-mer counting [spades] 0:00:03.006 15M / 15M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 36 files using 6 threads. This might take a while. [spades] 0:00:03.037 15M / 15M INFO General (file_limit.hpp : 32) Open file limit set to 131072 [spades] 0:00:03.037 15M / 15M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.6666 Gb [spades] 0:00:03.037 15M / 15M INFO General (kmer_splitters.hpp : 97) Using cell size of 1864135 [spades] 0:00:10.918 20M / 20M INFO General (kmer_splitters.hpp : 293) Used 2108 reads [spades] 0:00:10.928 20M / 20M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. [spades] 0:00:18.435 20M / 20M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 15413 kmers in total. [spades] 0:00:18.453 20M / 20M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. [spades] 0:00:24.795 20M / 20M INFO General (stage.cpp : 113) PROCEDURE == Extension index construction [spades] 0:00:24.842 20M / 20M INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index [spades] 0:00:24.844 20M / 20M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 96 files using 6 threads. This might take a while. [spades] 0:00:25.025 20M / 20M INFO General (file_limit.hpp : 32) Open file limit set to 131072 [spades] 0:00:25.040 20M / 20M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 1.66653 Gb [spades] 0:00:25.040 20M / 20M INFO General (kmer_splitters.hpp : 97) Using cell size of 699050 [spades] 0:00:48.105 4G / 4G INFO General (kmer_splitters.hpp : 364) Processed 15413 kmers [spades] 0:00:48.134 4G / 4G INFO General (kmer_splitters.hpp : 369) Used 15413 kmers. [spades] 0:00:48.204 117M / 117M INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. [spades] 0:01:03.723 117M / 117M INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 15262 kmers in total. [spades] 0:01:03.735 117M / 117M INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. [spades] 0:01:07.327 117M / 117M INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices [spades] 0:01:07.674 106M / 106M INFO General (kmer_index_builder.hpp : 150) Merging final buckets. [spades] 0:01:08.523 106M / 106M INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 15920 bytes occupied (8.34491 bits per kmer). [spades] 0:01:08.524 106M / 106M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers [spades] 0:01:08.582 106M / 106M INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. [spades] 0:01:08.592 100M / 100M INFO General (stage.cpp : 113) PROCEDURE == Early tip clipping [spades] 0:01:08.593 100M / 100M INFO General (construction.cpp : 293) Early tip clipper length bound set as (RL - K) [spades] 0:01:08.593 100M / 100M INFO Early tip clipping (early_simplification.hpp : 28) Early tip clipping [spades] 0:01:08.660 100M / 100M INFO Early tip clipping (early_simplification.hpp : 63) #tipped junctions: 213 [spades] 0:01:08.661 100M / 100M INFO Early tip clipping (early_simplification.hpp : 74) Clipped tips: 214 [spades] 0:01:08.662 100M / 100M INFO Early tip clipping (early_simplification.hpp : 30) 5963 32-mers were removed by early tip clipper [spades] 0:01:08.662 100M / 100M INFO General (stage.cpp : 113) PROCEDURE == Condensing graph [spades] 0:01:08.705 100M / 100M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 354) Extracting unbranching paths [spades] 0:01:08.709 100M / 100M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 373) Extracting unbranching paths finished. 442 sequences extracted [spades] 0:01:08.710 100M / 100M INFO UnbranchingPathExtractor (debruijn_graph_constructor: 3 .. (pair_info_count.cpp : 39) Selecting usual mapper [spades] 0:02:10.428 32M / 120M INFO General (sequence_mapper_notifier.h: 94) Total 1000 reads processed [spades] 0:02:10.445 23M / 120M INFO StageManager (stage.cpp : 166) STAGE == Distance Estimation [spades] 0:02:10.447 23M / 120M INFO General (distance_estimation.cpp : 174) Processing library #0 [spades] 0:02:10.447 23M / 120M INFO General (distance_estimation.cpp : 150) Weight Filter Done [spades] 0:02:10.450 23M / 120M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator [spades] 0:02:10.459 23M / 120M INFO General (distance_estimation.cpp : 35) Filtering info [spades] 0:02:10.460 23M / 120M INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2 [spades] 0:02:10.460 23M / 120M INFO General (pair_info_filters.hpp : 263) Done filtering [spades] 0:02:10.460 23M / 120M INFO General (distance_estimation.cpp : 157) Refining clustered pair information [spades] 0:02:10.460 23M / 120M INFO General (distance_estimation.cpp : 159) The refining of clustered pair information has been finished [spades] 0:02:10.460 23M / 120M INFO General (distance_estimation.cpp : 161) Improving paired information [spades] 0:02:10.466 23M / 120M INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 0; contradictional = 0 [spades] 0:02:10.467 23M / 120M INFO PairInfoImprover (pair_info_improver.hpp : 102) Paired info stats: missing = 0; contradictional = 0 [spades] 0:02:10.467 23M / 120M INFO General (distance_estimation.cpp : 104) Filling scaffolding index [spades] 0:02:10.467 23M / 120M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator [spades] 0:02:10.469 23M / 120M INFO General (distance_estimation.cpp : 35) Filtering info [spades] 0:02:10.470 23M / 120M INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 2 [spades] 0:02:10.470 23M / 120M INFO General (pair_info_filters.hpp : 263) Done filtering [spades] 0:02:10.470 23M / 120M INFO General (distance_estimation.cpp : 183) Clearing raw paired index [spades] 0:02:10.470 23M / 120M INFO StageManager (stage.cpp : 166) STAGE == Repeat Resolving [spades] 0:02:10.473 23M / 120M INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving [spades] 0:02:10.477 23M / 120M INFO General (launcher.cpp : 538) ExSPAnder repeat resolving tool started [spades] 0:02:10.581 23M / 120M INFO General (launcher.cpp : 404) Creating main extenders, unique edge length = 2000 [spades] 0:02:10.583 23M / 120M INFO General (extenders_logic.cpp : 311) Estimated coverage of library #0 is 61.014 [spades] 0:02:10.583 23M / 120M INFO General (extenders_logic.cpp : 311) Estimated coverage of library #0 is 61.014 [spades] 0:02:10.583 23M / 120M INFO General (extenders_logic.cpp : 519) Using 1 paired-end library [spades] 0:02:10.584 23M / 120M INFO General (extenders_logic.cpp : 520) Using 1 paired-end scaffolding library [spades] 0:02:10.584 23M / 120M INFO General (extenders_logic.cpp : 521) Using 0 single read libraries [spades] 0:02:10.584 23M / 120M INFO General (launcher.cpp : 432) Total number of extenders is 3 [spades] 0:02:10.623 23M / 120M INFO General (launcher.cpp : 244) Finalizing paths [spades] 0:02:10.624 23M / 120M INFO General (launcher.cpp : 246) Deduplicating paths [spades] 0:02:10.624 23M / 120M INFO General (launcher.cpp : 250) Paths deduplicated [spades] 0:02:10.624 23M / 120M INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps [spades] 0:02:10.624 23M / 120M INFO PEResolver (pe_resolver.hpp : 298) Sorting paths [spades] 0:02:10.624 23M / 120M INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps [spades] 0:02:10.624 23M / 120M INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps [spades] 0:02:10.624 23M / 120M INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps [spades] 0:02:10.625 23M / 120M INFO PEResolver (pe_resolver.hpp : 308) Splitting paths [spades] 0:02:10.625 23M / 120M INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths [spades] 0:02:10.625 23M / 120M INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed [spades] 0:02:10.625 23M / 120M INFO General (launcher.cpp : 267) Paths finalized [spades] 0:02:10.625 23M / 120M INFO General (launcher.cpp : 439) Closing gaps in paths [spades] 0:02:10.625 23M / 120M INFO General (launcher.cpp : 467) Gap closing completed [spades] 0:02:10.626 23M / 120M INFO General (launcher.cpp : 296) Traversing tandem repeats [spades] 0:02:10.630 23M / 120M INFO General (launcher.cpp : 306) Traversed 0 loops [spades] 0:02:10.630 23M / 120M INFO General (launcher.cpp : 244) Finalizing paths [spades] 0:02:10.630 23M / 120M INFO General (launcher.cpp : 246) Deduplicating paths [spades] 0:02:10.631 23M / 120M INFO General (launcher.cpp : 250) Paths deduplicated [spades] 0:02:10.631 23M / 120M INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps [spades] 0:02:10.631 23M / 120M INFO PEResolver (pe_resolver.hpp : 298) Sorting paths [spades] 0:02:10.631 23M / 120M INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps [spades] 0:02:10.631 23M / 120M INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps [spades] 0:02:10.631 23M / 120M INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps [spades] 0:02:10.631 23M / 120M INFO PEResolver (pe_resolver.hpp : 308) Splitting paths [spades] 0:02:10.632 23M / 120M INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths [spades] 0:02:10.632 23M / 120M INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed [spades] 0:02:10.632 23M / 120M INFO General (launcher.cpp : 267) Paths finalized [spades] 0:02:10.632 23M / 120M INFO General (launcher.cpp : 596) ExSPAnder repeat resolving tool finished [spades] 0:02:10.632 22M / 120M INFO StageManager (stage.cpp : 166) STAGE == Contig Output [spades] 0:02:10.633 22M / 120M INFO General (contig_output.hpp : 21) Outputting contigs to /corral4/main/jobs/044/273/44273376/working/out/spades/K111/before_rr.fasta [spades] 0:02:10.744 22M / 120M INFO General (contig_output_stage.cpp : 146) Writing GFA graph to /corral4/main/jobs/044/273/44273376/working/out/spades/K111/assembly_graph_with_scaffolds.gfa [spades] 0:02:10.747 22M / 120M INFO General (contig_output_stage.cpp : 160) Outputting FastG graph to /corral4/main/jobs/044/273/44273376/working/out/spades/K111/assembly_graph.fastg [spades] 0:02:10.820 22M / 120M INFO General (contig_output_stage.cpp : 190) Breaking scaffolds [spades] 0:02:10.820 22M / 120M INFO General (contig_output_stage.cpp : 95) Outputting contigs to /corral4/main/jobs/044/273/44273376/working/out/spades/K111/final_contigs.fasta [spades] 0:02:10.883 22M / 120M INFO General (contig_output_stage.cpp : 101) Outputting FastG paths to /corral4/main/jobs/044/273/44273376/working/out/spades/K111/final_contigs.paths [spades] 0:02:10.965 22M / 120M INFO General (contig_output_stage.cpp : 95) Outputting contigs to /corral4/main/jobs/044/273/44273376/working/out/spades/K111/scaffolds.fasta [spades] 0:02:11.035 22M / 120M INFO General (contig_output_stage.cpp : 101) Outputting FastG paths to /corral4/main/jobs/044/273/44273376/working/out/spades/K111/scaffolds.paths [spades] 0:02:11.145 22M / 120M INFO General (contig_output_stage.cpp : 108) Populating GFA with scaffold paths [spades] 0:02:11.281 22M / 120M INFO General (pipeline.cpp : 259) SPAdes finished [spades] 0:02:11.393 22M / 120M INFO General (main.cpp : 107) Assembling time: 0 hours 2 minutes 12 seconds [spades] [spades] ===== K111 finished. [spades] [spades] [spades] ===== Copy files started. [spades] [spades] [spades] == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/copy_files.py /corral4/main/jobs/044/273/44273376/working/out/spades/K111/before_rr.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/before_rr.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/K111/assembly_graph_after_simplification.gfa /corral4/main/jobs/044/273/44273376/working/out/spades/assembly_graph_after_simplification.gfa /corral4/main/jobs/044/273/44273376/working/out/spades/K111/final_contigs.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/contigs.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/K111/first_pe_contigs.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/first_pe_contigs.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/K111/strain_graph.gfa /corral4/main/jobs/044/273/44273376/working/out/spades/strain_graph.gfa /corral4/main/jobs/044/273/44273376/working/out/spades/K111/scaffolds.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/scaffolds.fasta /corral4/main/jobs/044/273/44273376/working/out/spades/K111/scaffolds.paths /corral4/main/jobs/044/273/44273376/working/out/spades/scaffolds.paths /corral4/main/jobs/044/273/44273376/working/out/spades/K111/assembly_graph_with_scaffolds.gfa /corral4/main/jobs/044/273/44273376/working/out/spades/assembly_graph_with_scaffolds.gfa /corral4/main/jobs/044/273/44273376/working/out/spades/K111/assembly_graph.fastg /corral4/main/jobs/044/273/44273376/working/out/spades/assembly_graph.fastg /corral4/main/jobs/044/273/44273376/working/out/spades/K111/final_contigs.paths /corral4/main/jobs/044/273/44273376/working/out/spades/contigs.paths [spades] [spades] [spades] ===== Copy files finished. [spades] [spades] [spades] ===== Assembling finished. [spades] [spades] [spades] ===== Breaking scaffolds started. [spades] [spades] [spades] == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/breaking_scaffolds_script.py --result_scaffolds_filename /corral4/main/jobs/044/273/44273376/working/out/spades/scaffolds.fasta --misc_dir /corral4/main/jobs/044/273/44273376/working/out/spades/misc --threshold_for_breaking_scaffolds 3 [spades] [spades] [spades] ===== Breaking scaffolds finished. [spades] [spades] [spades] ===== Terminate started. [spades] [spades] [spades] ===== Terminate finished. [spades] [spades] * Assembled contigs are in /corral4/main/jobs/044/273/44273376/working/out/spades/contigs.fasta [spades] * Assembled scaffolds are in /corral4/main/jobs/044/273/44273376/working/out/spades/scaffolds.fasta [spades] * Paths in the assembly graph corresponding to the contigs are in /corral4/main/jobs/044/273/44273376/working/out/spades/contigs.paths [spades] * Paths in the assembly graph corresponding to the scaffolds are in /corral4/main/jobs/044/273/44273376/working/out/spades/scaffolds.paths [spades] * Assembly graph is in /corral4/main/jobs/044/273/44273376/working/out/spades/assembly_graph.fastg [spades] * Assembly graph in GFA format is in /corral4/main/jobs/044/273/44273376/working/out/spades/assembly_graph_with_scaffolds.gfa [spades] [spades] ======= SPAdes pipeline finished. [spades] [spades] SPAdes log can be found here: /corral4/main/jobs/044/273/44273376/working/out/spades/spades.log [spades] [spades] Thank you for using SPAdes! [bwa-index] [bwa_index] Pack FASTA... 0.00 sec [bwa-index] [bwa_index] Construct BWT for the packed sequence... [bwa-index] [bwa_index] 0.00 seconds elapse. [bwa-index] [bwa_index] Update BWT... 0.00 sec [bwa-index] [bwa_index] Pack forward-only FASTA... 0.00 sec [bwa-index] [bwa_index] Construct SA from BWT and Occ... 0.00 sec [bwa-index] [main] Version: 0.7.17-r1188 [bwa-index] [main] CMD: bwa index spades.fasta [bwa-index] [main] Real time: 1.221 sec; CPU: 0.023 sec [bwa+samtools-sort] [M::bwa_idx_load_from_disk] read 0 ALT contigs [bwa+samtools-sort] [samclip] samclip 0.4.0 by Torsten Seemann (@torstenseemann) [bwa+samtools-sort] [samclip] Loading: spades.fasta.fai [bwa+samtools-sort] [samclip] Found 1 sequences in spades.fasta.fai [bwa+samtools-sort] [M::process] read 2000 sequences (300000 bp)... [bwa+samtools-sort] [M::mem_pestat] # candidate unique pairs for (FF, FR, RF, RR): (0, 1000, 0, 0) [bwa+samtools-sort] [M::mem_pestat] skip orientation FF as there are not enough pairs [bwa+samtools-sort] [M::mem_pestat] analyzing insert size distribution for orientation FR... [bwa+samtools-sort] [M::mem_pestat] (25, 50, 75) percentile: (161, 197, 229) [bwa+samtools-sort] [M::mem_pestat] low and high boundaries for computing mean and std.dev: (25, 365) [bwa+samtools-sort] [M::mem_pestat] mean and std.dev: (200.03, 42.82) [bwa+samtools-sort] [M::mem_pestat] low and high boundaries for proper pairs: (1, 433) [bwa+samtools-sort] [M::mem_pestat] skip orientation RF as there are not enough pairs [bwa+samtools-sort] [M::mem_pestat] skip orientation RR as there are not enough pairs [bwa+samtools-sort] [M::mem_process_seqs] Processed 2000 reads in 0.309 CPU sec, 0.065 real sec [bwa+samtools-sort] [main] Version: 0.7.17-r1188 [bwa+samtools-sort] [main] CMD: bwa mem -v 3 -x intractg -t 6 spades.fasta R1.fq.gz R2.fq.gz [bwa+samtools-sort] [main] Real time: 2.124 sec; CPU: 0.392 sec [bwa+samtools-sort] [samclip] Total SAM records 2000, removed 158, allowed 294, passed 1842 [bwa+samtools-sort] [samclip] Header contained 2 lines [bwa+samtools-sort] [samclip] Done. [pilon] Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/corral4/main/jobs/044/273/44273376/_job_tmp -Xmx28g -Xms256m -Xmx30g [pilon] Pilon version 1.23 Mon Nov 26 16:04:05 2018 -0500 [pilon] Genome: spades.fasta [pilon] Fixing snps, indels [pilon] Input genome size: 1254 [pilon] Processing NODE_1_length_1254_cov_61.013998:1-1254 [pilon] NODE_1_length_1254_cov_61.013998:1-1254 log: [pilon] frags shovill.bam: coverage 191 [pilon] Total Reads: 1842, Coverage: 191, minDepth: 48 [pilon] Confirmed 1166 of 1254 bases (92.98%) [pilon] Corrected 0 snps; 0 ambiguous bases; corrected 0 small insertions totaling 0 bases, 0 small deletions totaling 0 bases [pilon] Finished processing NODE_1_length_1254_cov_61.013998:1-1254 [pilon] Writing NODE_1_length_1254_cov_61.013998:1-1254 changes to pilon.changes [pilon] Writing updated NODE_1_length_1254_cov_61.013998_pilon to pilon.fasta [pilon] Mean frags coverage: 191 [pilon] Mean total coverage: 191 ``` **Job Parameters:** * | Job parameter | Parameter value | | ------------- | --------------- | | library | ` {"R1": {"values": [{"id": 99730717, "src": "hda"}]}, "R2": {"values": [{"id": 99730731, "src": "hda"}]}, "__current_case__": 0, "lib_type": "paired"} ` | | trim | ` "true" ` | | log | ` "true" ` | | assembler | ` "spades" ` | | adv | ` {"depth": "0", "gsize": "", "kmers": "", "mincov": "0", "minlen": "0", "namefmt": "contig%03d", "nocorr": "false", "opts": ""} ` | | \_\_job\_resource | ` {"__current_case__": 0, "__job_resource__select": "no"} ` | | chromInfo | ` "/cvmfs/data.galaxyproject.org/managed/len/ucsc/?.len" ` | | dbkey | ` "?" ` | | \_\_input\_ext | ` "fastqsanger" ` |
• ✅ toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill (Test #3)

  **Command Line:** * ```console ``` **Exit Code:** * ```console 0 ``` **Standard Error:** * ```console [shovill] Hello g2main [shovill] You ran: /usr/local/bin/shovill --outdir out --cpus 6 --ram 29 --R1 fastq_r1.fastqsanger --R2 fastq_r2.fastqsanger --namefmt contig%05d --depth 100 --nocorr --minlen 0 --mincov 2 --assembler megahit [shovill] This is shovill 1.1.0 [shovill] Written by Torsten Seemann [shovill] Homepage is https://github.com/tseemann/shovill [shovill] Operating system is linux [shovill] Perl version is v5.26.2 [shovill] Machine has 10 CPU cores and 29.29 GB RAM [shovill] Using bwa - /usr/local/bin/bwa | Version: 0.7.17-r1188 [shovill] Using flash - /usr/local/bin/flash | FLASH v1.2.11 [shovill] Using java - /usr/local/bin/java | openjdk version "11.0.1" 2018-10-16 LTS [shovill] Using kmc - /usr/local/bin/kmc | K-Mer Counter (KMC) ver. 3.1.1 (2019-05-19) [shovill] Using lighter - /usr/local/bin/lighter | Lighter v1.1.2 [shovill] Using megahit - /usr/local/bin/megahit | MEGAHIT v1.2.9 [shovill] Using megahit_toolkit - /usr/local/bin/megahit_toolkit | v1.2.9 [shovill] Using pigz - /usr/local/bin/pigz | pigz 2.6 [shovill] Using pilon - /usr/local/bin/pilon | Pilon version 1.23 Mon Nov 26 16:04:05 2018 -0500 [shovill] Using samclip - /usr/local/bin/samclip | samclip 0.4.0 [shovill] Using samtools - /usr/local/bin/samtools | Version: 1.12 (using htslib 1.12) [shovill] Using seqtk - /usr/local/bin/seqtk | Version: 1.3-r106 [shovill] Using skesa - /usr/local/bin/skesa | SKESA 2.4.0 [shovill] Using spades.py - /usr/local/bin/spades.py | SPAdes genome assembler v3.14.1 [shovill] Using trimmomatic - /usr/local/bin/trimmomatic | 0.39 [shovill] Using velvetg - /usr/local/bin/velvetg | Version 1.2.10 [shovill] Using velveth - /usr/local/bin/velveth | Version 1.2.10 [shovill] Found spades version: 003014000 [shovill] Using tempdir: /corral4/main/jobs/044/273/44273372/_job_tmp [shovill] Changing into folder: /corral4/main/jobs/044/273/44273372/working/out [shovill] Collecting raw read statistics with 'seqtk' [shovill] Running: seqtk fqchk -q3 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat >/corral4/main/jobs/044/273/44273372/_job_tmp/qfVpXP8vox 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Read stats: min_len = 150 [shovill] Read stats: total_bp = 300000 [shovill] Read stats: max_len = 150 [shovill] Read stats: avg_len = 150 [shovill] Estimating genome size by counting unqiue 21-mers > frequency 10 [shovill] Running: kmc -sm -m14 -t6 -k21 -ci10 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat /corral4/main/jobs/044/273/44273372/_job_tmp/oadncmuHoG/kmc /corral4/main/jobs/044/273/44273372/_job_tmp/oadncmuHoG 2>&1 | sed 's/^/[kmc] /' | tee -a shovill.log [shovill] Using genome size 1188 bp [shovill] Estimated sequencing depth: 252 x [shovill] Subsampling reads by factor 0.397 to get from 252x to 100x [shovill] Running: seqtk sample \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat 0.397 | pigz --fast -c -p 6 > R1.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Running: seqtk sample \/corral4\/main\/objects\/3\/6\/e\/dataset_36e11e53\-e2b5\-46ec\-bb32\-f57f5aa02e03\.dat 0.397 | pigz --fast -c -p 6 > R2.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Appending -Xmx29g to _JAVA_OPTIONS [shovill] Running: ln -sf R1\.sub\.fq\.gz R1.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Running: ln -sf R2\.sub\.fq\.gz R2.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Average read length looks like 150 bp [shovill] Automatically setting --minlen to 75 [shovill] Setting k-mer range to (31 .. 112) [shovill] Estimated K-mers: 31 51 71 91 111 [kn=5, ks=20, kmin=31, kmax=112] [shovill] Using kmers: 31,51,71,91,111 [shovill] Correcting reads with 'Lighter' [shovill] Running: lighter -od . -r R1.fq.gz -r R2.fq.gz -K 32 1188 -t 6 -maxcor 1 2>&1 | sed 's/^/[lighter] /' | tee -a shovill.log [shovill] Overlapping/stitching PE reads with 'FLASH' [shovill] Running: flash -m 20 -M 150 -d . -o flash -z -t 6 R1.cor.fq.gz R2.cor.fq.gz 2>&1 | sed 's/^//' | tee -a shovill.log [shovill] Assembling reads with 'megahit' [shovill] Running: megahit -1 flash.notCombined_1.fastq.gz -2 flash.notCombined_2.fastq.gz --k-list 31,51,71,91,111 -m 29000000000 -t 6 -o megahit --tmp-dir /corral4/main/jobs/044/273/44273372/_job_tmp --min-contig-len 1 -r flash.extendedFrags.fastq.gz 2>&1 | sed 's/^/[megahit] /' | tee -a shovill.log [shovill] Generating genome graph from K=111 [shovill] Running: megahit_toolkit contig2fastg 111 megahit/intermediate_contigs/k111.contigs.fa > megahit/contigs.fastg 2>&1 | sed 's/^/[megahit_toolkit] /' | tee -a shovill.log [shovill] User supplied --nocorr, so not correcting contigs. [shovill] Assembly is 1242, estimated genome size was 1188 (+4.55%) [shovill] Using genome graph file 'megahit/contigs.fastg' => 'contigs.fastg' [shovill] Walltime used: 0 min 41 sec [shovill] Results in: /corral4/main/jobs/044/273/44273372/working/out [shovill] Final assembly graph: /corral4/main/jobs/044/273/44273372/working/out/contigs.fastg [shovill] Final assembly contigs: /corral4/main/jobs/044/273/44273372/working/out/contigs.fa [shovill] It contains 1 (min=75) contigs totalling 1242 bp. [shovill] Remember, an assembly is just a _hypothesis_ of the original sequence! [shovill] Done. ``` **Standard Output:** * ```console [kmc] ** [kmc] Stage 1: 0% Stage 1: 100% [kmc] Stage 2: 0% Stage 2: 84% Stage 2: 90% Stage 2: 94% Stage 2: 96% Stage 2: 98% Stage 2: 99% Stage 2: 100% [kmc] [kmc] 1st stage: 3.91876s [kmc] 2nd stage: 1.8842s [kmc] 3rd stage: 0.037257s [kmc] Total : 5.84022s [kmc] Tmp size : 0MB [kmc] Tmp size strict memory : 0MB [kmc] Tmp total: 0MB [kmc] [kmc] Stats: [kmc] No. of k-mers below min. threshold : 34495 [kmc] No. of k-mers above max. threshold : 0 [kmc] No. of unique k-mers : 35683 [kmc] No. of unique counted k-mers : 1188 [kmc] Total no. of k-mers : 130000 [kmc] Total no. of reads : 1000 [kmc] Total no. of super-k-mers : 18576 [lighter] [2022-06-30 18:21:21] =============Start==================== [lighter] [2022-06-30 18:21:21] Scanning the input files to infer alpha(sampling rate) [lighter] [2022-06-30 18:21:21] Average coverage is 103.535 and alpha is 0.068 [lighter] [2022-06-30 18:21:21] Bad quality threshold is "1" [lighter] [2022-06-30 18:21:21] Finish sampling kmers [lighter] [2022-06-30 18:21:21] Bloom filter A's false positive rate: 0.264464 [lighter] [2022-06-30 18:21:21] Finish storing trusted kmers [lighter] [2022-06-30 18:21:21] Finish error correction [lighter] Processed 820 reads: [lighter] 48 are error-free [lighter] Corrected 1731 bases(2.242228 corrections for reads with errors) [lighter] Trimmed 0 reads with average trimmed bases 0.000000 [lighter] Discard 0 reads [FLASH] Starting FLASH v1.2.11 [FLASH] Fast Length Adjustment of SHort reads [FLASH] [FLASH] Input files: [FLASH] R1.cor.fq.gz [FLASH] R2.cor.fq.gz [FLASH] [FLASH] Output files: [FLASH] ./flash.extendedFrags.fastq.gz [FLASH] ./flash.notCombined_1.fastq.gz [FLASH] ./flash.notCombined_2.fastq.gz [FLASH] ./flash.hist [FLASH] ./flash.histogram [FLASH] [FLASH] Parameters: [FLASH] Min overlap: 20 [FLASH] Max overlap: 150 [FLASH] Max mismatch density: 0.250000 [FLASH] Allow "outie" pairs: false [FLASH] Cap mismatch quals: false [FLASH] Combiner threads: 6 [FLASH] Input format: FASTQ, phred_offset=33 [FLASH] Output format: FASTQ, phred_offset=33, gzip [FLASH] [FLASH] Starting reader and writer threads [FLASH] Starting 6 combiner threads [FLASH] Processed 410 read pairs [FLASH] [FLASH] Read combination statistics: [FLASH] Total pairs: 410 [FLASH] Combined pairs: 387 [FLASH] Uncombined pairs: 23 [FLASH] Percent combined: 94.39% [FLASH] [FLASH] Writing histogram files. [FLASH] [FLASH] FLASH v1.2.11 complete! [FLASH] 0.077 seconds elapsed [megahit] 2022-06-30 18:21:22 - MEGAHIT v1.2.9 [megahit] 2022-06-30 18:21:22 - Using megahit_core with POPCNT and BMI2 support [megahit] 2022-06-30 18:21:22 - Convert reads to binary library [megahit] 2022-06-30 18:21:22 - b'INFO sequence/io/sequence_lib.cpp : 75 - Lib 0 (/corral4/main/jobs/044/273/44273372/working/out/flash.notCombined_1.fastq.gz,/corral4/main/jobs/044/273/44273372/working/out/flash.notCombined_2.fastq.gz): pe, 46 reads, 150 max length' [megahit] 2022-06-30 18:21:22 - b'INFO sequence/io/sequence_lib.cpp : 75 - Lib 1 (/corral4/main/jobs/044/273/44273372/working/out/flash.extendedFrags.fastq.gz): se, 387 reads, 280 max length' [megahit] 2022-06-30 18:21:22 - b'INFO utils/utils.h : 152 - Real: 0.0726\tuser: 0.0048\tsys: 0.0036\tmaxrss: 9200' [megahit] 2022-06-30 18:21:22 - Start assembly. Number of CPU threads 6 [megahit] 2022-06-30 18:21:22 - k list: 31,51,71,91,111 [megahit] 2022-06-30 18:21:22 - Memory used: 29000000000 [megahit] 2022-06-30 18:21:22 - Extract solid (k+1)-mers for k = 31 [megahit] 2022-06-30 18:21:22 - Build graph for k = 31 [megahit] 2022-06-30 18:21:23 - Assemble contigs from SdBG for k = 31 [megahit] 2022-06-30 18:21:24 - Local assembly for k = 31 [megahit] 2022-06-30 18:21:24 - Extract iterative edges from k = 31 to 51 [megahit] 2022-06-30 18:21:24 - Build graph for k = 51 [megahit] 2022-06-30 18:21:24 - Assemble contigs from SdBG for k = 51 [megahit] 2022-06-30 18:21:24 - Local assembly for k = 51 [megahit] 2022-06-30 18:21:25 - Extract iterative edges from k = 51 to 71 [megahit] 2022-06-30 18:21:25 - Build graph for k = 71 [megahit] 2022-06-30 18:21:25 - Assemble contigs from SdBG for k = 71 [megahit] 2022-06-30 18:21:26 - Local assembly for k = 71 [megahit] 2022-06-30 18:21:26 - Extract iterative edges from k = 71 to 91 [megahit] 2022-06-30 18:21:26 - Build graph for k = 91 [megahit] 2022-06-30 18:21:26 - Assemble contigs from SdBG for k = 91 [megahit] 2022-06-30 18:21:27 - Local assembly for k = 91 [megahit] 2022-06-30 18:21:27 - Extract iterative edges from k = 91 to 111 [megahit] 2022-06-30 18:21:27 - Build graph for k = 111 [megahit] 2022-06-30 18:21:28 - Assemble contigs from SdBG for k = 111 [megahit] 2022-06-30 18:21:28 - Merging to output final contigs [megahit] 2022-06-30 18:21:28 - 1 contigs, total 1242 bp, min 1242 bp, max 1242 bp, avg 1242 bp, N50 1242 bp [megahit] 2022-06-30 18:21:28 - ALL DONE. Time elapsed: 6.202115 seconds ``` **Job Parameters:** * | Job parameter | Parameter value | | ------------- | --------------- | | library | ` {"R1": {"values": [{"id": 99730717, "src": "hda"}]}, "R2": {"values": [{"id": 99730731, "src": "hda"}]}, "__current_case__": 0, "lib_type": "paired"} ` | | trim | ` "false" ` | | log | ` "true" ` | | assembler | ` "megahit" ` | | adv | ` {"depth": "100", "gsize": "", "kmers": "", "mincov": "2", "minlen": "0", "namefmt": "contig%05d", "nocorr": "true", "opts": ""} ` | | \_\_job\_resource | ` {"__current_case__": 0, "__job_resource__select": "no"} ` | | chromInfo | ` "/cvmfs/data.galaxyproject.org/managed/len/ucsc/?.len" ` | | dbkey | ` "?" ` | | \_\_input\_ext | ` "fastqsanger" ` |
• ✅ toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill (Test #4)

  **Command Line:** * ```console ``` **Exit Code:** * ```console 0 ``` **Standard Error:** * ```console [shovill] Hello g2main [shovill] You ran: /usr/local/bin/shovill --outdir out --cpus 6 --ram 30 --R1 fastq_r1.fastqsanger --R2 fastq_r2.fastqsanger --namefmt contig%05d --depth 100 --nocorr --minlen 0 --mincov 2 --assembler skesa [shovill] This is shovill 1.1.0 [shovill] Written by Torsten Seemann [shovill] Homepage is https://github.com/tseemann/shovill [shovill] Operating system is linux [shovill] Perl version is v5.26.2 [shovill] Machine has 32 CPU cores and 125.71 GB RAM [shovill] Using bwa - /usr/local/bin/bwa | Version: 0.7.17-r1188 [shovill] Using flash - /usr/local/bin/flash | FLASH v1.2.11 [shovill] Using java - /usr/local/bin/java | openjdk version "11.0.1" 2018-10-16 LTS [shovill] Using kmc - /usr/local/bin/kmc | K-Mer Counter (KMC) ver. 3.1.1 (2019-05-19) [shovill] Using lighter - /usr/local/bin/lighter | Lighter v1.1.2 [shovill] Using megahit - /usr/local/bin/megahit | MEGAHIT v1.2.9 [shovill] Using megahit_toolkit - /usr/local/bin/megahit_toolkit | v1.2.9 [shovill] Using pigz - /usr/local/bin/pigz | pigz 2.6 [shovill] Using pilon - /usr/local/bin/pilon | Pilon version 1.23 Mon Nov 26 16:04:05 2018 -0500 [shovill] Using samclip - /usr/local/bin/samclip | samclip 0.4.0 [shovill] Using samtools - /usr/local/bin/samtools | Version: 1.12 (using htslib 1.12) [shovill] Using seqtk - /usr/local/bin/seqtk | Version: 1.3-r106 [shovill] Using skesa - /usr/local/bin/skesa | SKESA 2.4.0 [shovill] Using spades.py - /usr/local/bin/spades.py | SPAdes genome assembler v3.14.1 [shovill] Using trimmomatic - /usr/local/bin/trimmomatic | 0.39 [shovill] Using velvetg - /usr/local/bin/velvetg | Version 1.2.10 [shovill] Using velveth - /usr/local/bin/velveth | Version 1.2.10 [shovill] Found spades version: 003014000 [shovill] Using tempdir: /corral4/main/jobs/044/273/44273371/_job_tmp [shovill] Changing into folder: /corral4/main/jobs/044/273/44273371/working/out [shovill] Collecting raw read statistics with 'seqtk' [shovill] Running: seqtk fqchk -q3 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat >/corral4/main/jobs/044/273/44273371/_job_tmp/YF5vHhCVFX 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Read stats: min_len = 150 [shovill] Read stats: total_bp = 300000 [shovill] Read stats: avg_len = 150 [shovill] Read stats: max_len = 150 [shovill] Estimating genome size by counting unqiue 21-mers > frequency 10 [shovill] Running: kmc -sm -m15 -t6 -k21 -ci10 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat /corral4/main/jobs/044/273/44273371/_job_tmp/XsHy14WsP9/kmc /corral4/main/jobs/044/273/44273371/_job_tmp/XsHy14WsP9 2>&1 | sed 's/^/[kmc] /' | tee -a shovill.log [shovill] Using genome size 1188 bp [shovill] Estimated sequencing depth: 252 x [shovill] Subsampling reads by factor 0.397 to get from 252x to 100x [shovill] Running: seqtk sample \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat 0.397 | pigz --fast -c -p 6 > R1.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Running: seqtk sample \/corral4\/main\/objects\/3\/6\/e\/dataset_36e11e53\-e2b5\-46ec\-bb32\-f57f5aa02e03\.dat 0.397 | pigz --fast -c -p 6 > R2.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Appending -Xmx30g to _JAVA_OPTIONS [shovill] Running: ln -sf R1\.sub\.fq\.gz R1.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Running: ln -sf R2\.sub\.fq\.gz R2.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Average read length looks like 150 bp [shovill] Automatically setting --minlen to 75 [shovill] Setting k-mer range to (31 .. 112) [shovill] Estimated K-mers: 31 51 71 91 111 [kn=5, ks=20, kmin=31, kmax=112] [shovill] Using kmers: 31,51,71,91,111 [shovill] Correcting reads with 'Lighter' [shovill] Running: lighter -od . -r R1.fq.gz -r R2.fq.gz -K 32 1188 -t 6 -maxcor 1 2>&1 | sed 's/^/[lighter] /' | tee -a shovill.log [shovill] Overlapping/stitching PE reads with 'FLASH' [shovill] Running: flash -m 20 -M 150 -d . -o flash -z -t 6 R1.cor.fq.gz R2.cor.fq.gz 2>&1 | sed 's/^//' | tee -a shovill.log [shovill] Assembling reads with 'skesa' [shovill] Running: skesa --gz --fastq flash.extendedFrags.fastq.gz --fastq flash.notCombined_1.fastq.gz,flash.notCombined_2.fastq.gz --use_paired_ends --contigs_out skesa.fasta --min_contig 1 --memory 30 --cores 6 --vector_percent 1 2>&1 | sed 's/^/[skesa] /' | tee -a shovill.log [shovill] User supplied --nocorr, so not correcting contigs. [shovill] Assembly is 1127, estimated genome size was 1188 (-5.13%) [shovill] Note: skesa does not produce a graph file [shovill] Walltime used: 0 min 11 sec [shovill] Results in: /corral4/main/jobs/044/273/44273371/working/out [shovill] Final assembly contigs: /corral4/main/jobs/044/273/44273371/working/out/contigs.fa [shovill] It contains 1 (min=75) contigs totalling 1127 bp. [shovill] More correct contigs is better than fewer wrong contigs. [shovill] Done. ``` **Standard Output:** * ```console [kmc] ** [kmc] Stage 1: 0% Stage 1: 100% [kmc] Stage 2: 0% Stage 2: 84% Stage 2: 90% Stage 2: 94% Stage 2: 96% Stage 2: 98% Stage 2: 99% Stage 2: 100% [kmc] [kmc] 1st stage: 2.89s [kmc] 2nd stage: 0.709927s [kmc] 3rd stage: 0.011046s [kmc] Total : 3.61098s [kmc] Tmp size : 0MB [kmc] Tmp size strict memory : 0MB [kmc] Tmp total: 0MB [kmc] [kmc] Stats: [kmc] No. of k-mers below min. threshold : 34495 [kmc] No. of k-mers above max. threshold : 0 [kmc] No. of unique k-mers : 35683 [kmc] No. of unique counted k-mers : 1188 [kmc] Total no. of k-mers : 130000 [kmc] Total no. of reads : 1000 [kmc] Total no. of super-k-mers : 18576 [lighter] [2022-06-30 13:20:02] =============Start==================== [lighter] [2022-06-30 13:20:02] Scanning the input files to infer alpha(sampling rate) [lighter] [2022-06-30 13:20:02] Average coverage is 103.535 and alpha is 0.068 [lighter] [2022-06-30 13:20:03] Bad quality threshold is "1" [lighter] [2022-06-30 13:20:04] Finish sampling kmers [lighter] [2022-06-30 13:20:04] Bloom filter A's false positive rate: 0.264464 [lighter] [2022-06-30 13:20:04] Finish storing trusted kmers [lighter] [2022-06-30 13:20:04] Finish error correction [lighter] Processed 820 reads: [lighter] 48 are error-free [lighter] Corrected 1731 bases(2.242228 corrections for reads with errors) [lighter] Trimmed 0 reads with average trimmed bases 0.000000 [lighter] Discard 0 reads [FLASH] Starting FLASH v1.2.11 [FLASH] Fast Length Adjustment of SHort reads [FLASH] [FLASH] Input files: [FLASH] R1.cor.fq.gz [FLASH] R2.cor.fq.gz [FLASH] [FLASH] Output files: [FLASH] ./flash.extendedFrags.fastq.gz [FLASH] ./flash.notCombined_1.fastq.gz [FLASH] ./flash.notCombined_2.fastq.gz [FLASH] ./flash.hist [FLASH] ./flash.histogram [FLASH] [FLASH] Parameters: [FLASH] Min overlap: 20 [FLASH] Max overlap: 150 [FLASH] Max mismatch density: 0.250000 [FLASH] Allow "outie" pairs: false [FLASH] Cap mismatch quals: false [FLASH] Combiner threads: 6 [FLASH] Input format: FASTQ, phred_offset=33 [FLASH] Output format: FASTQ, phred_offset=33, gzip [FLASH] [FLASH] Starting reader and writer threads [FLASH] Starting 6 combiner threads [FLASH] Processed 410 read pairs [FLASH] [FLASH] Read combination statistics: [FLASH] Total pairs: 410 [FLASH] Combined pairs: 387 [FLASH] Uncombined pairs: 23 [FLASH] Percent combined: 94.39% [FLASH] [FLASH] Writing histogram files. [FLASH] [FLASH] FLASH v1.2.11 complete! [FLASH] 0.019 seconds elapsed [skesa] skesa --gz --fastq flash.extendedFrags.fastq.gz --fastq flash.notCombined_1.fastq.gz,flash.notCombined_2.fastq.gz --use_paired_ends --contigs_out skesa.fasta --min_contig 1 --memory 30 --cores 6 --vector_percent 1 [skesa] [skesa] WARNING: option --gz is deprecated - gzipped files are now recognized automatically [skesa] Total mates: 433 Paired reads: 23 [skesa] Reads acquired in 0.023304s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] Adapters clip is disabled [skesa] [skesa] Kmer len: 21 [skesa] Raw kmers: 74923 Memory needed (GB): 0.00143852 Memory available (GB): 28 1 cycle(s) will be performed [skesa] Distinct kmers: 1298 [skesa] Kmer count in 0.011015s wall, 0.030000s user + 0.010000s system = 0.040000s CPU (363.2%) [skesa] Uniq kmers merging in 0.001936s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] WARNING: --min_count changed from 2 to 19 because of high coverage for genome size 87 [skesa] WARNING: --max_kmer_count 10 to 96 because of high coverage for genome size 87 [skesa] Kmers branching in 0.000849s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] [skesa] Average read length: 193 [skesa] Genome size estimate: 8 [skesa] [skesa] Kmer: 21 Graph size: 1149 Contigs in: 0 [skesa] Valley: 0 [skesa] [skesa] Mark used kmers in 0.000008s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] Kmers in multiple/single contigs: 0 0 [skesa] Fragments before: 14 1149 [skesa] Fragments after: 1 1149 [skesa] New seeds: 1 [skesa] New seeds in 0.002125s wall, 0.000000s user + 0.010000s system = 0.010000s CPU (470.6%) [skesa] Fragments before: 2 42 [skesa] Fragments after: 2 42 [skesa] Connectors: 0 Extenders: 2 [skesa] Connections and extensions in 0.000704s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] Contigs out: 1 Genome: 1127 N50: 1127 L50: 1 [skesa] Assembled in 0.002920s wall, 0.000000s user + 0.010000s system = 0.010000s CPU (342.5%) [skesa] [skesa] [skesa] Average count: 19.375 Max kmer: 21 [skesa] Connected: 22 ambiguously connected: 0 from 23 mate pairs [skesa] Connect pairs in 0.017156s wall, 0.020000s user + 0.000000s system = 0.020000s CPU (116.6%) [skesa] [skesa] N50 for inserts: 288 [skesa] [skesa] Seed kmers: 0 [skesa] Cleaned reads: 142 [skesa] Reads for connection: 4 [skesa] Internal reads: 2 [skesa] Reads cleaned in 0.001202s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] WARNING: iterations are disabled [skesa] [skesa] Connecting mate pairs using kmer length: 21 [skesa] Connected: 2 ambiguously connected: 0 from 2 mate pairs [skesa] Connect pairs in 0.001422s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] Totally connected: 2 [skesa] Added notconnected: 0 [skesa] [skesa] Kmer len: 25 [skesa] Raw kmers: 1068 Memory needed (GB): 2.0505e-05 Memory available (GB): 28 1 cycle(s) will be performed [skesa] Distinct kmers: 0 [skesa] Kmer count in 0.001113s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] Uniq kmers merging in 0.000411s wall, 0.000000s user + 0.000000s system = 0.000000s CPU (n/a%) [skesa] Empty graph for kmer length: 25 skipping this and longer kmers [skesa] DONE ``` **Job Parameters:** * | Job parameter | Parameter value | | ------------- | --------------- | | library | ` {"R1": {"values": [{"id": 99730717, "src": "hda"}]}, "R2": {"values": [{"id": 99730731, "src": "hda"}]}, "__current_case__": 0, "lib_type": "paired"} ` | | trim | ` "false" ` | | log | ` "true" ` | | assembler | ` "skesa" ` | | adv | ` {"depth": "100", "gsize": "", "kmers": "", "mincov": "2", "minlen": "0", "namefmt": "contig%05d", "nocorr": "true", "opts": ""} ` | | \_\_job\_resource | ` {"__current_case__": 0, "__job_resource__select": "no"} ` | | chromInfo | ` "/cvmfs/data.galaxyproject.org/managed/len/ucsc/?.len" ` | | dbkey | ` "?" ` | | \_\_input\_ext | ` "fastqsanger" ` |
• ✅ toolshed.g2.bx.psu.edu/repos/iuc/shovill/shovill (Test #5)

  **Command Line:** * ```console ``` **Exit Code:** * ```console 0 ``` **Standard Error:** * ```console [shovill] Hello g2main [shovill] You ran: /usr/local/bin/shovill --outdir out --cpus 6 --ram 29 --R1 fastq_r1.fastqsanger --R2 fastq_r2.fastqsanger --namefmt contig%05d --depth 100 --nocorr --minlen 0 --mincov 2 --assembler velvet [shovill] This is shovill 1.1.0 [shovill] Written by Torsten Seemann [shovill] Homepage is https://github.com/tseemann/shovill [shovill] Operating system is linux [shovill] Perl version is v5.26.2 [shovill] Machine has 10 CPU cores and 29.29 GB RAM [shovill] Using bwa - /usr/local/bin/bwa | Version: 0.7.17-r1188 [shovill] Using flash - /usr/local/bin/flash | FLASH v1.2.11 [shovill] Using java - /usr/local/bin/java | openjdk version "11.0.1" 2018-10-16 LTS [shovill] Using kmc - /usr/local/bin/kmc | K-Mer Counter (KMC) ver. 3.1.1 (2019-05-19) [shovill] Using lighter - /usr/local/bin/lighter | Lighter v1.1.2 [shovill] Using megahit - /usr/local/bin/megahit | MEGAHIT v1.2.9 [shovill] Using megahit_toolkit - /usr/local/bin/megahit_toolkit | v1.2.9 [shovill] Using pigz - /usr/local/bin/pigz | pigz 2.6 [shovill] Using pilon - /usr/local/bin/pilon | Pilon version 1.23 Mon Nov 26 16:04:05 2018 -0500 [shovill] Using samclip - /usr/local/bin/samclip | samclip 0.4.0 [shovill] Using samtools - /usr/local/bin/samtools | Version: 1.12 (using htslib 1.12) [shovill] Using seqtk - /usr/local/bin/seqtk | Version: 1.3-r106 [shovill] Using skesa - /usr/local/bin/skesa | SKESA 2.4.0 [shovill] Using spades.py - /usr/local/bin/spades.py | SPAdes genome assembler v3.14.1 [shovill] Using trimmomatic - /usr/local/bin/trimmomatic | 0.39 [shovill] Using velvetg - /usr/local/bin/velvetg | Version 1.2.10 [shovill] Using velveth - /usr/local/bin/velveth | Version 1.2.10 [shovill] Found spades version: 003014000 [shovill] Using tempdir: /corral4/main/jobs/044/273/44273408/_job_tmp [shovill] Changing into folder: /corral4/main/jobs/044/273/44273408/working/out [shovill] Collecting raw read statistics with 'seqtk' [shovill] Running: seqtk fqchk -q3 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat >/corral4/main/jobs/044/273/44273408/_job_tmp/HQoBqsNocL 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Read stats: max_len = 150 [shovill] Read stats: total_bp = 300000 [shovill] Read stats: min_len = 150 [shovill] Read stats: avg_len = 150 [shovill] Estimating genome size by counting unqiue 21-mers > frequency 10 [shovill] Running: kmc -sm -m14 -t6 -k21 -ci10 \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat /corral4/main/jobs/044/273/44273408/_job_tmp/vmFXWLhRRh/kmc /corral4/main/jobs/044/273/44273408/_job_tmp/vmFXWLhRRh 2>&1 | sed 's/^/[kmc] /' | tee -a shovill.log [shovill] Using genome size 1188 bp [shovill] Estimated sequencing depth: 252 x [shovill] Subsampling reads by factor 0.397 to get from 252x to 100x [shovill] Running: seqtk sample \/corral4\/main\/objects\/1\/6\/0\/dataset_160df692\-9804\-452e\-b575\-c79f5910295c\.dat 0.397 | pigz --fast -c -p 6 > R1.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Running: seqtk sample \/corral4\/main\/objects\/3\/6\/e\/dataset_36e11e53\-e2b5\-46ec\-bb32\-f57f5aa02e03\.dat 0.397 | pigz --fast -c -p 6 > R2.sub.fq.gz 2>&1 | sed 's/^/[seqtk] /' | tee -a shovill.log [shovill] Appending -Xmx29g to _JAVA_OPTIONS [shovill] Running: ln -sf R1\.sub\.fq\.gz R1.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Running: ln -sf R2\.sub\.fq\.gz R2.fq.gz 2>&1 | sed 's/^/[ln] /' | tee -a shovill.log [shovill] Average read length looks like 150 bp [shovill] Automatically setting --minlen to 75 [shovill] Setting k-mer range to (31 .. 112) [shovill] Estimated K-mers: 31 51 71 91 111 [kn=5, ks=20, kmin=31, kmax=112] [shovill] Using kmers: 31,51,71,91,111 [shovill] Correcting reads with 'Lighter' [shovill] Running: lighter -od . -r R1.fq.gz -r R2.fq.gz -K 32 1188 -t 6 -maxcor 1 2>&1 | sed 's/^/[lighter] /' | tee -a shovill.log [shovill] Overlapping/stitching PE reads with 'FLASH' [shovill] Running: flash -m 20 -M 150 -d . -o flash -z -t 6 R1.cor.fq.gz R2.cor.fq.gz 2>&1 | sed 's/^//' | tee -a shovill.log [shovill] Assembling reads with 'velvet' [shovill] Using K=71 for velveth [shovill] Running: OMP_NUM_THREADS=6 velveth velvet 71 -create_binary -shortPaired -fmtAuto -separate flash.notCombined_1.fastq.gz flash.notCombined_2.fastq.gz -short2 -fmtAuto flash.extendedFrags.fastq.gz 2>&1 | sed 's/^/[velveth] /' | tee -a shovill.log [shovill] Running: OMP_NUM_THREADS=6 velvetg velvet -exp_cov auto -cov_cutoff auto -scaffolding yes 2>&1 | sed 's/^/[velvetg] /' | tee -a shovill.log [shovill] User supplied --nocorr, so not correcting contigs. [shovill] Assembly is 989, estimated genome size was 1188 (-16.75%) [shovill] Using genome graph file 'velvet/contigs.LastGraph' => 'contigs.LastGraph' [shovill] Walltime used: 0 min 10 sec [shovill] Results in: /corral4/main/jobs/044/273/44273408/working/out [shovill] Final assembly graph: /corral4/main/jobs/044/273/44273408/working/out/contigs.LastGraph [shovill] Final assembly contigs: /corral4/main/jobs/044/273/44273408/working/out/contigs.fa [shovill] It contains 1 (min=75) contigs totalling 989 bp. [shovill] Have a suggestion for shovill? Tell me at https://github.com/tseemann/shovill/issues [shovill] Done. ``` **Standard Output:** * ```console [kmc] ** [kmc] Stage 1: 0% Stage 1: 100% [kmc] Stage 2: 0% Stage 2: 84% Stage 2: 90% Stage 2: 94% Stage 2: 96% Stage 2: 98% Stage 2: 99% Stage 2: 100% [kmc] [kmc] 1st stage: 2.57858s [kmc] 2nd stage: 1.09474s [kmc] 3rd stage: 0.072041s [kmc] Total : 3.74537s [kmc] Tmp size : 0MB [kmc] Tmp size strict memory : 0MB [kmc] Tmp total: 0MB [kmc] [kmc] Stats: [kmc] No. of k-mers below min. threshold : 34495 [kmc] No. of k-mers above max. threshold : 0 [kmc] No. of unique k-mers : 35683 [kmc] No. of unique counted k-mers : 1188 [kmc] Total no. of k-mers : 130000 [kmc] Total no. of reads : 1000 [kmc] Total no. of super-k-mers : 18576 [lighter] [2022-06-30 18:25:53] =============Start==================== [lighter] [2022-06-30 18:25:53] Scanning the input files to infer alpha(sampling rate) [lighter] [2022-06-30 18:25:53] Average coverage is 103.535 and alpha is 0.068 [lighter] [2022-06-30 18:25:53] Bad quality threshold is "1" [lighter] [2022-06-30 18:25:53] Finish sampling kmers [lighter] [2022-06-30 18:25:53] Bloom filter A's false positive rate: 0.264464 [lighter] [2022-06-30 18:25:53] Finish storing trusted kmers [lighter] [2022-06-30 18:25:53] Finish error correction [lighter] Processed 820 reads: [lighter] 48 are error-free [lighter] Corrected 1731 bases(2.242228 corrections for reads with errors) [lighter] Trimmed 0 reads with average trimmed bases 0.000000 [lighter] Discard 0 reads [FLASH] Starting FLASH v1.2.11 [FLASH] Fast Length Adjustment of SHort reads [FLASH] [FLASH] Input files: [FLASH] R1.cor.fq.gz [FLASH] R2.cor.fq.gz [FLASH] [FLASH] Output files: [FLASH] ./flash.extendedFrags.fastq.gz [FLASH] ./flash.notCombined_1.fastq.gz [FLASH] ./flash.notCombined_2.fastq.gz [FLASH] ./flash.hist [FLASH] ./flash.histogram [FLASH] [FLASH] Parameters: [FLASH] Min overlap: 20 [FLASH] Max overlap: 150 [FLASH] Max mismatch density: 0.250000 [FLASH] Allow "outie" pairs: false [FLASH] Cap mismatch quals: false [FLASH] Combiner threads: 6 [FLASH] Input format: FASTQ, phred_offset=33 [FLASH] Output format: FASTQ, phred_offset=33, gzip [FLASH] [FLASH] Starting reader and writer threads [FLASH] Starting 6 combiner threads [FLASH] Processed 410 read pairs [FLASH] [FLASH] Read combination statistics: [FLASH] Total pairs: 410 [FLASH] Combined pairs: 387 [FLASH] Uncombined pairs: 23 [FLASH] Percent combined: 94.39% [FLASH] [FLASH] Writing histogram files. [FLASH] [FLASH] FLASH v1.2.11 complete! [FLASH] 0.077 seconds elapsed [velveth] [0.000000] Reading file 'flash.notCombined_1.fastq.gz' using 'pigz' as FastQ [velveth] [0.005987] Reading file 'flash.notCombined_2.fastq.gz' using 'pigz' as FastQ [velveth] [0.006570] 46 sequences found in total in the paired sequence files [velveth] [0.006572] Done [velveth] [0.012230] Reading file 'flash.extendedFrags.fastq.gz' using 'pigz' as FastQ [velveth] [0.016501] 387 sequences found [velveth] [0.016503] Done [velveth] [0.067391] Reading CNY read set file velvet/CnyUnifiedSeq [velveth] [0.067461] 433 sequences found [velveth] [0.067582] Done [velveth] [0.067583] 433 sequences in total. [velveth] [0.073264] Writing into roadmap file velvet/Roadmaps... [velveth] [0.073343] Inputting sequences... [velveth] [0.073742] Inputting sequence 0 / 433 [velveth] [0.139268] === Sequences loaded in 0.065986 s [velveth] [0.140651] Done inputting sequences [velveth] [0.140654] Destroying splay table [velveth] [0.144613] Splay table destroyed [velvetg] [0.000000] Reading roadmap file velvet/Roadmaps [velvetg] [0.002181] 433 roadmaps read [velvetg] [0.002769] Reading CNY read set file velvet/CnyUnifiedSeq [velvetg] [0.002826] 433 sequences found [velvetg] [0.003019] Done [velvetg] [0.003091] Creating insertion markers [velvetg] [0.003159] Ordering insertion markers [velvetg] [0.003857] Counting preNodes [velvetg] [0.003938] 692 preNodes counted, creating them now [velvetg] [0.006582] Adjusting marker info... [velvetg] [0.006695] Connecting preNodes [velvetg] [0.007728] Cleaning up memory [velvetg] [0.007729] Done creating preGraph [velvetg] [0.007730] Concatenation... [velvetg] [0.008047] Renumbering preNodes [velvetg] [0.008047] Initial preNode count 692 [velvetg] [0.008072] Destroyed 510 preNodes [velvetg] [0.008073] Concatenation over! [velvetg] [0.008074] Clipping short tips off preGraph [velvetg] [0.008104] Concatenation... [velvetg] [0.008177] Renumbering preNodes [velvetg] [0.008177] Initial preNode count 182 [velvetg] [0.008186] Destroyed 124 preNodes [velvetg] [0.008187] Concatenation over! [velvetg] [0.008187] 64 tips cut off [velvetg] [0.008188] 58 nodes left [velvetg] [0.010554] Writing into pregraph file velvet/PreGraph... [velvetg] [0.020317] Reading pre-graph file velvet/PreGraph [velvetg] [0.020337] Graph has 58 nodes and 433 sequences [velvetg] [0.021266] Scanning pre-graph file velvet/PreGraph for k-mers [velvetg] [0.021542] 2841 kmers found [velvetg] [0.022933] Sorting kmer occurence table ... [velvetg] [0.023621] Sorting done. [velvetg] [0.023622] Computing acceleration table... [velvetg] [0.071896] Computing offsets... [velvetg] [0.072090] Ghost Threading through reads 0 / 433 [velvetg] [0.073963] === Ghost-Threaded in 0.001998 s [velvetg] [0.073968] Threading through reads 0 / 433 [velvetg] [0.081458] === Threaded in 0.007493 s [velvetg] [0.087850] Correcting graph with cutoff 0.200000 [velvetg] [0.087888] Determining eligible starting points [velvetg] [0.087930] Done listing starting nodes [velvetg] [0.087930] Initializing todo lists [velvetg] [0.087935] Done with initilization [velvetg] [0.087936] Activating arc lookup table [velvetg] [0.087939] Done activating arc lookup table [velvetg] [0.089709] Concatenation... [velvetg] [0.089712] Renumbering nodes [velvetg] [0.089712] Initial node count 58 [velvetg] [0.089714] Removed 33 null nodes [velvetg] [0.089714] Concatenation over! [velvetg] [0.089715] Clipping short tips off graph, drastic [velvetg] [0.089719] Concatenation... [velvetg] [0.089719] Renumbering nodes [velvetg] [0.089720] Initial node count 25 [velvetg] [0.089721] Removed 9 null nodes [velvetg] [0.089721] Concatenation over! [velvetg] [0.089721] 16 nodes left [velvetg] [0.091117] Writing into graph file velvet/Graph2... [velvetg] [0.093485] Measuring median coverage depth... [velvetg] [0.093494] Median coverage depth = 39.993266 [velvetg] [0.094431] Removing contigs with coverage < 19.996633... [velvetg] [0.094446] Concatenation... [velvetg] [0.094556] Renumbering nodes [velvetg] [0.094557] Initial node count 16 [velvetg] [0.094557] Removed 15 null nodes [velvetg] [0.094558] Concatenation over! [velvetg] [0.094558] Concatenation... [velvetg] [0.094559] Renumbering nodes [velvetg] [0.094559] Initial node count 1 [velvetg] [0.094559] Removed 0 null nodes [velvetg] [0.094560] Concatenation over! [velvetg] [0.094564] Clipping short tips off graph, drastic [velvetg] [0.094565] Concatenation... [velvetg] [0.094565] Renumbering nodes [velvetg] [0.094566] Initial node count 1 [velvetg] [0.094566] Removed 0 null nodes [velvetg] [0.094567] Concatenation over! [velvetg] [0.094567] 1 nodes left [velvetg] [0.094567] Read coherency... [velvetg] [0.094568] Identifying unique nodes [velvetg] [0.094568] Done, 1 unique nodes counted [velvetg] [0.094569] Trimming read tips [velvetg] [0.094569] Renumbering nodes [velvetg] [0.094570] Initial node count 1 [velvetg] [0.094570] Removed 0 null nodes [velvetg] [0.094570] Confronted to 0 multiple hits and 0 null over 0 [velvetg] [0.094571] Read coherency over! [velvetg] [0.094577] Starting pebble resolution... [velvetg] [0.094583] Computing read to node mapping array sizes [velvetg] [0.094703] Computing read to node mappings [velvetg] [0.094748] Estimating library insert lengths... [velvetg] [0.094754] Paired-end library 1 has length: 290, sample standard deviation: 8 [velvetg] [0.094756] Done [velvetg] [0.094756] Computing direct node to node mappings [velvetg] [0.094769] Scaffolding node 0 [velvetg] [0.094782] === Nodes Scaffolded in 0.000026 s [velvetg] [0.094787] Preparing to correct graph with cutoff 0.200000 [velvetg] [0.094821] Cleaning memory [velvetg] [0.094858] Deactivating local correction settings [velvetg] [0.094864] Pebble done. [velvetg] [0.094865] Starting pebble resolution... [velvetg] [0.094869] Computing read to node mapping array sizes [velvetg] [0.094882] Computing read to node mappings [velvetg] [0.094928] Estimating library insert lengths... [velvetg] [0.094934] Paired-end library 1 has length: 290, sample standard deviation: 8 [velvetg] [0.094935] Done [velvetg] [0.094936] Computing direct node to node mappings [velvetg] [0.094942] Scaffolding node 0 [velvetg] [0.094952] === Nodes Scaffolded in 0.000016 s [velvetg] [0.094956] Preparing to correct graph with cutoff 0.200000 [velvetg] [0.094981] Cleaning memory [velvetg] [0.094982] Deactivating local correction settings [velvetg] [0.094987] Pebble done. [velvetg] [0.094987] Concatenation... [velvetg] [0.094987] Renumbering nodes [velvetg] [0.094988] Initial node count 1 [velvetg] [0.094989] Removed 0 null nodes [velvetg] [0.094989] Concatenation over! [velvetg] [0.094990] Removing reference contigs with coverage < 19.996633... [velvetg] [0.094992] Concatenation... [velvetg] [0.094992] Renumbering nodes [velvetg] [0.094992] Initial node count 1 [velvetg] [0.094993] Removed 0 null nodes [velvetg] [0.094993] Concatenation over! [velvetg] [0.099426] Writing contigs into velvet/contigs.fa... [velvetg] [0.116526] Writing into stats file velvet/stats.txt... [velvetg] [0.126061] Writing into graph file velvet/LastGraph... [velvetg] [0.127563] Estimated Coverage = 39.993266 [velvetg] [0.127572] Estimated Coverage cutoff = 19.996633 [velvetg] Final graph has 1 nodes and n50 of 919, max 919, total 919, using 363/433 reads ``` **Job Parameters:** * | Job parameter | Parameter value | | ------------- | --------------- | | library | ` {"R1": {"values": [{"id": 99730717, "src": "hda"}]}, "R2": {"values": [{"id": 99730731, "src": "hda"}]}, "__current_case__": 0, "lib_type": "paired"} ` | | trim | ` "false" ` | | log | ` "true" ` | | assembler | ` "velvet" ` | | adv | ` {"depth": "100", "gsize": "", "kmers": "", "mincov": "2", "minlen": "0", "namefmt": "contig%05d", "nocorr": "true", "opts": ""} ` | | \_\_job\_resource | ` {"__current_case__": 0, "__job_resource__select": "no"} ` | | chromInfo | ` "/cvmfs/data.galaxyproject.org/managed/len/ucsc/?.len" ` | | dbkey | ` "?" ` | | \_\_input\_ext | ` "fastqsanger" ` |

[mvdbeek]

Results (powered by Planemo)

Summary

State	Count
Total	3
Passed	2
Error	0
Failure	1
Skipped	0

Failed s

*

❌ toolshed.g2.bx.psu.edu/repos/nml/metaspades/metaspades (Test #3)

**Problems**: * ``` ('Connection aborted.', ConnectionResetError(104, 'Connection reset by peer')) ```

Passed s

*

✅ toolshed.g2.bx.psu.edu/repos/nml/metaspades/metaspades (Test #1)

**Command Line:** * ```console ``` **Exit Code:** * ```console 0 ``` **Standard Output:** * ```console Command line: /usr/local/bin/metaspades.py -o /corral4/main/jobs/044/273/44273407/working/output -t 6 -m 29 --pe-12 1 /corral4/main/jobs/044/273/44273407/working/reads1/ecoli_1K.fastq.gz.fastq.gz --pe-or 1 fr System information: SPAdes version: 3.15.3 Python version: 3.8.12 OS: Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-glibc2.10 Output dir: /corral4/main/jobs/044/273/44273407/working/output Mode: read error correction and assembling Debug mode is turned OFF Dataset parameters: Metagenomic mode Reads: Library number: 1, library type: paired-end orientation: fr left reads: not specified right reads: not specified interlaced reads: ['/corral4/main/jobs/044/273/44273407/working/reads1/ecoli_1K.fastq.gz.fastq.gz'] single reads: not specified merged reads: not specified Read error correction parameters: Iterations: 1 PHRED offset will be auto-detected Corrected reads will be compressed Assembly parameters: k: [21, 33, 55] Repeat resolution is enabled Mismatch careful mode is turned OFF MismatchCorrector will be SKIPPED Coverage cutoff is turned OFF Other parameters: Dir for temp files: /corral4/main/jobs/044/273/44273407/working/output/tmp Threads: 6 Memory limit (in Gb): 29 ======= SPAdes pipeline started. Log can be found here: /corral4/main/jobs/044/273/44273407/working/output/spades.log /corral4/main/jobs/044/273/44273407/working/reads1/ecoli_1K.fastq.gz.fastq.gz: max reads length: 100 Reads length: 100 ===== Before start started. ===== Preprocess reads started. ===== Preprocess interlaced reads started. == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/preprocess_interlaced_reads.py --args_filename /corral4/main/jobs/044/273/44273407/working/output/split_input/tmp/interlaced --dst /corral4/main/jobs/044/273/44273407/working/output/split_input == Splitting /corral4/main/jobs/044/273/44273407/working/reads1/ecoli_1K.fastq.gz.fastq.gz into left and right reads (in /corral4/main/jobs/044/273/44273407/working/output/split_input directory) ===== Preprocess interlaced reads finished. ===== Preprocess reads finished. ===== Read error correction started. ===== Read error correction started. == Running: /usr/local/bin/spades-hammer /corral4/main/jobs/044/273/44273407/working/output/corrected/configs/config.info 0:00:00.000 1M / 18M INFO General (main.cpp : 75) Starting BayesHammer, built from N/A, git revision N/A 0:00:00.000 1M / 18M INFO General (main.cpp : 76) Loading config from /corral4/main/jobs/044/273/44273407/working/output/corrected/configs/config.info 0:00:00.001 1M / 18M INFO General (main.cpp : 78) Maximum # of threads to use (adjusted due to OMP capabilities): 6 0:00:00.001 1M / 18M INFO General (memory_limit.cpp : 48) Memory limit set to 29 Gb 0:00:00.001 1M / 18M INFO General (main.cpp : 86) Trying to determine PHRED offset 0:00:00.003 1M / 18M INFO General (main.cpp : 92) Determined value is 33 0:00:00.003 1M / 18M INFO General (hammer_tools.cpp : 38) Hamming graph threshold tau=1, k=21, subkmer positions = [ 0 10 ] 0:00:00.003 1M / 18M INFO General (main.cpp : 113) Size of aux. kmer data 24 bytes === ITERATION 0 begins === 0:00:00.003 1M / 18M INFO K-mer Counting (kmer_data.cpp : 283) Estimating k-mer count 0:00:00.032 97M / 113M INFO K-mer Counting (kmer_data.cpp : 288) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_1.fastq 0:00:00.040 97M / 113M INFO K-mer Counting (kmer_data.cpp : 288) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_2.fastq 0:00:00.047 97M / 113M INFO K-mer Counting (kmer_data.cpp : 302) Total 4108 reads processed 0:00:00.271 97M / 113M INFO K-mer Counting (kmer_data.cpp : 305) Estimated 2171 distinct kmers 0:00:00.271 1M / 113M INFO K-mer Counting (kmer_data.cpp : 309) Filtering singleton k-mers 0:00:00.271 1M / 113M INFO K-mer Counting (kmer_data.cpp : 315) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_1.fastq 0:00:00.420 1M / 113M INFO K-mer Counting (kmer_data.cpp : 315) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_2.fastq 0:00:00.552 1M / 113M INFO K-mer Counting (kmer_data.cpp : 329) Total 4108 reads processed 0:00:00.556 1M / 113M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 16 files using 6 threads. This might take a while. 0:00:00.561 1M / 113M INFO General (file_limit.hpp : 32) Open file limit set to 131072 0:00:00.561 1M / 113M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 1.61111 Gb 0:00:00.561 1M / 113M INFO General (kmer_splitter.hpp : 101) Using cell size of 4194304 0:00:00.600 3457M / 3457M INFO K-mer Splitting (kmer_data.cpp : 97) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_1.fastq 0:00:00.716 3457M / 3457M INFO K-mer Splitting (kmer_data.cpp : 97) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_2.fastq 0:00:00.812 3457M / 3457M INFO K-mer Splitting (kmer_data.cpp : 112) Total 4108 reads processed 0:00:00.812 1M / 329M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:00:00.895 1M / 329M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 1974 kmers in total. 0:00:00.897 1M / 329M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:00:00.932 1M / 329M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 1974 kmers, 13944 bytes occupied (56.5106 bits per kmer). 0:00:00.940 1M / 329M INFO K-mer Counting (kmer_data.cpp : 354) Arranging kmers in hash map order 0:00:01.033 1M / 329M INFO General (main.cpp : 148) Clustering Hamming graph. 0:00:01.038 1M / 329M INFO General (main.cpp : 155) Extracting clusters: 0:00:01.038 1M / 329M INFO General (concurrent_dsu.cpp : 18) Connecting to root 0:00:01.038 1M / 329M INFO General (concurrent_dsu.cpp : 34) Calculating counts 0:00:01.038 1M / 329M INFO General (concurrent_dsu.cpp : 63) Writing down entries 0:00:01.050 1M / 329M INFO General (main.cpp : 167) Clustering done. Total clusters: 1960 0:00:01.050 1M / 329M INFO K-mer Counting (kmer_data.cpp : 371) Collecting K-mer information, this takes a while. 0:00:01.050 1M / 329M INFO K-mer Counting (kmer_data.cpp : 377) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_1.fastq 0:00:01.081 1M / 329M INFO K-mer Counting (kmer_data.cpp : 377) Processing /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_2.fastq 0:00:01.108 1M / 329M INFO K-mer Counting (kmer_data.cpp : 384) Collection done, postprocessing. 0:00:01.108 1M / 329M INFO K-mer Counting (kmer_data.cpp : 397) There are 1974 kmers in total. Among them 0 (0%) are singletons. 0:00:01.108 1M / 329M INFO General (main.cpp : 173) Subclustering Hamming graph 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 650) Subclustering done. Total 0 non-read kmers were generated. 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 651) Subclustering statistics: 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 652) Total singleton hamming clusters: 1946. Among them 1946 (100%) are good 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 653) Total singleton subclusters: 8. Among them 8 (100%) are good 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 654) Total non-singleton subcluster centers: 10. Among them 10 (100%) are good 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 655) Average size of non-trivial subcluster: 2.8 kmers 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 656) Average number of sub-clusters per non-singleton cluster: 1.28571 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 657) Total solid k-mers: 1964 0:00:01.117 1M / 329M INFO Hamming Subclustering (kmer_cluster.cpp : 658) Substitution probabilities: [4,4]((0.875,0.125,0,0),(0,1,0,0),(0,0,1,0),(0,0,0.125,0.875)) 0:00:01.118 1M / 329M INFO General (main.cpp : 178) Finished clustering. 0:00:01.118 1M / 329M INFO General (main.cpp : 197) Starting solid k-mers expansion in 6 threads. 0:00:01.129 1M / 329M INFO General (main.cpp : 218) Solid k-mers iteration 0 produced 0 new k-mers. 0:00:01.129 1M / 329M INFO General (main.cpp : 222) Solid k-mers finalized 0:00:01.129 1M / 329M INFO General (hammer_tools.cpp : 222) Starting read correction in 6 threads. 0:00:01.129 1M / 329M INFO General (hammer_tools.cpp : 235) Correcting pair of reads: /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_1.fastq and /corral4/main/jobs/044/273/44273407/working/output/split_input/ecoli_1K.fastq.gz_2.fastq 0:00:01.186 138M / 329M INFO General (hammer_tools.cpp : 170) Prepared batch 0 of 2054 reads. 0:00:01.194 138M / 329M INFO General (hammer_tools.cpp : 177) Processed batch 0 0:00:01.198 138M / 329M INFO General (hammer_tools.cpp : 187) Written batch 0 0:00:01.237 1M / 329M INFO General (hammer_tools.cpp : 276) Correction done. Changed 4 bases in 4 reads. 0:00:01.238 1M / 329M INFO General (hammer_tools.cpp : 277) Failed to correct 0 bases out of 353915. 0:00:01.238 1M / 329M INFO General (main.cpp : 255) Saving corrected dataset description to /corral4/main/jobs/044/273/44273407/working/output/corrected/corrected.yaml 0:00:01.258 1M / 329M INFO General (main.cpp : 262) All done. Exiting. ===== Read error correction finished. ===== corrected reads compression started. == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/compress_all.py --input_file /corral4/main/jobs/044/273/44273407/working/output/corrected/corrected.yaml --ext_python_modules_home /usr/local/share/spades --max_threads 6 --output_dir /corral4/main/jobs/044/273/44273407/working/output/corrected --gzip_output == Compressing corrected reads (with gzip) == Files to compress: ['/corral4/main/jobs/044/273/44273407/working/output/corrected/ecoli_1K.fastq.gz_1.00.0_0.cor.fastq', '/corral4/main/jobs/044/273/44273407/working/output/corrected/ecoli_1K.fastq.gz_2.00.0_0.cor.fastq', '/corral4/main/jobs/044/273/44273407/working/output/corrected/ecoli_1K.fastq.gz__unpaired.00.0_0.cor.fastq'] == Files compression is finished == Dataset yaml file is updated ===== corrected reads compression finished. ===== Read error correction finished. ===== Assembling started. ===== K21 started. == Running: /usr/local/bin/spades-core /corral4/main/jobs/044/273/44273407/working/output/K21/configs/config.info /corral4/main/jobs/044/273/44273407/working/output/K21/configs/mda_mode.info /corral4/main/jobs/044/273/44273407/working/output/K21/configs/meta_mode.info 0:00:00.000 1M / 18M INFO General (main.cpp : 99) Loaded config from /corral4/main/jobs/044/273/44273407/working/output/K21/configs/config.info 0:00:00.000 1M / 18M INFO General (main.cpp : 99) Loaded config from /corral4/main/jobs/044/273/44273407/working/output/K21/configs/mda_mode.info 0:00:00.000 1M / 18M INFO General (main.cpp : 99) Loaded config from /corral4/main/jobs/044/273/44273407/working/output/K21/configs/meta_mode.info 0:00:00.000 1M / 18M INFO General (memory_limit.cpp : 48) Memory limit set to 29 Gb 0:00:00.000 1M / 18M INFO General (main.cpp : 107) Starting SPAdes, built from N/A, git revision N/A 0:00:00.000 1M / 18M INFO General (main.cpp : 108) Maximum k-mer length: 128 0:00:00.000 1M / 18M INFO General (main.cpp : 109) Assembling dataset (/corral4/main/jobs/044/273/44273407/working/output/dataset.info) with K=21 0:00:00.000 1M / 18M INFO General (main.cpp : 110) Maximum # of threads to use (adjusted due to OMP capabilities): 6 0:00:00.000 1M / 18M INFO General (pipeline.cpp : 212) SPAdes started 0:00:00.000 1M / 18M INFO General (pipeline.cpp : 225) Starting from stage: read_conversion 0:00:00.000 1M / 18M INFO General (pipeline.cpp : 231) Two-step repeat resolution disabled 0:00:00.011 1M / 18M INFO GraphCore (graph_core.hpp : 672) Graph created, vertex min_id: 3, edge min_id: 3 0:00:00.011 1M / 18M INFO GraphCore (graph_core.hpp : 673) Vertex size: 48, edge size: 40 0:00:00.011 1M / 18M INFO General (edge_index.hpp : 113) Size of edge index entries: 12/8 0:00:00.011 1M / 18M INFO StageManager (stage.cpp : 185) STAGE == Binary Read Conversion (id: read_conversion) 0:00:00.015 1M / 18M INFO General (read_converter.cpp : 72) Converting reads to binary format for library #0 (takes a while) 0:00:00.016 1M / 18M INFO General (read_converter.cpp : 73) Converting paired reads 0:00:00.045 63M / 63M INFO General (binary_converter.cpp : 111) 2054 reads written 0:00:00.045 41M / 41M INFO General (read_converter.cpp : 86) Converting single reads 0:00:00.079 71M / 71M INFO General (binary_converter.cpp : 111) 0 reads written 0:00:00.079 61M / 61M INFO General (read_converter.cpp : 92) Converting merged reads 0:00:00.102 71M / 71M INFO General (binary_converter.cpp : 111) 0 reads written 0:00:00.148 1M / 22M INFO StageManager (stage.cpp : 185) STAGE == de Bruijn graph construction (id: constructi .. al (contig_output.hpp : 16) Outputting contigs to /corral4/main/jobs/044/273/44273407/working/output/K55/before_rr.fasta 0:00:05.542 1M / 396M INFO General (contig_output_stage.cpp : 151) Writing GFA graph to /corral4/main/jobs/044/273/44273407/working/output/K55/assembly_graph_after_simplification.gfa 0:00:05.543 1M / 396M INFO StageManager (stage.cpp : 185) STAGE == Paired Information Counting (id: late_pair_info_count) 0:00:05.543 1M / 396M INFO General (graph_pack.cpp : 77) Normalizing k-mer map. Total 0 kmers to process 0:00:05.543 1M / 396M INFO General (graph_pack.cpp : 79) Normalizing done 0:00:05.543 1M / 396M INFO General (pair_info_count.cpp : 339) Min edge length for estimation: 900 0:00:05.543 1M / 396M INFO General (pair_info_count.cpp : 350) Estimating insert size for library #0 0:00:05.543 1M / 396M INFO General (pair_info_count.cpp : 202) Estimating insert size (takes a while) 0:00:05.573 113M / 396M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:05.746 113M / 396M INFO General (sequence_mapper_notifier.h: 95) Total 2054 reads processed 0:00:05.871 113M / 396M INFO General (pair_info_count.cpp : 220) Edge pairs: 4 0:00:05.871 113M / 396M INFO General (pair_info_count.cpp : 222) 608 paired reads (29.6008% of all) aligned to long edges 0:00:05.872 1M / 396M INFO General (pair_info_count.cpp : 369) Insert size = 338.201, deviation = 219.594, left quantile = 71, right quantile = 658, read length = 100 0:00:05.872 1M / 396M INFO General (pair_info_count.cpp : 390) Filtering data for library #0 0:00:05.897 1M / 396M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:05.900 1M / 396M INFO General (sequence_mapper_notifier.h: 95) Total 2054 reads processed 0:00:05.900 1M / 396M INFO General (pair_info_count.cpp : 402) Mapping library #0 0:00:05.900 1M / 396M INFO General (pair_info_count.cpp : 404) Mapping paired reads (takes a while) 0:00:05.900 1M / 396M INFO General (pair_info_count.cpp : 299) Left insert size quantile 71, right insert size quantile 658, filtering threshold 1, rounding threshold 0 0:00:05.969 10M / 396M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:05.976 10M / 396M INFO General (sequence_mapper_notifier.h: 95) Total 2054 reads processed 0:00:05.982 1M / 396M INFO General (pair_info_count.cpp : 346) Mapping contigs library #1 0:00:05.983 1M / 396M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:06.009 1M / 396M INFO General (sequence_mapper_notifier.h: 95) Total 1 reads processed 0:00:06.010 1M / 396M INFO StageManager (stage.cpp : 185) STAGE == Distance Estimation (id: distance_estimation) 0:00:06.010 1M / 396M INFO General (distance_estimation.cpp : 179) Processing library #0 0:00:06.010 1M / 396M INFO General (distance_estimation.cpp : 150) Weight Filter Done 0:00:06.010 1M / 396M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 0:00:06.010 1M / 396M INFO General (distance_estimation.cpp : 37) Filtering info 0:00:06.010 1M / 396M INFO General (pair_info_filters.hpp : 242) Start filtering; library index size: 2 0:00:06.010 1M / 396M INFO General (pair_info_filters.hpp : 263) Done filtering; library index size: 2 0:00:06.010 1M / 396M INFO General (distance_estimation.cpp : 156) Refining clustered pair information 0:00:06.010 1M / 396M INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 0:00:06.010 1M / 396M INFO General (distance_estimation.cpp : 160) Improving paired information 0:00:06.011 1M / 396M INFO PairInfoImprover (pair_info_improver.hpp : 104) Paired info stats: missing = 0; contradictional = 0 0:00:06.011 1M / 396M INFO PairInfoImprover (pair_info_improver.hpp : 104) Paired info stats: missing = 0; contradictional = 0 0:00:06.011 1M / 396M INFO General (distance_estimation.cpp : 104) Filling scaffolding index 0:00:06.011 1M / 396M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator 0:00:06.044 1M / 396M INFO General (distance_estimation.cpp : 37) Filtering info 0:00:06.044 1M / 396M INFO General (pair_info_filters.hpp : 242) Start filtering; library index size: 4 0:00:06.044 1M / 396M INFO General (pair_info_filters.hpp : 263) Done filtering; library index size: 4 0:00:06.044 1M / 396M INFO General (distance_estimation.cpp : 186) Clearing raw paired index 0:00:06.044 1M / 396M INFO StageManager (stage.cpp : 185) STAGE == Repeat Resolving (id: repeat_resolving) 0:00:06.044 1M / 396M INFO General (repeat_resolving.cpp : 87) Using Path-Extend repeat resolving 0:00:06.044 1M / 396M INFO General (launcher.cpp : 600) ExSPAnder repeat resolving tool started 0:00:06.047 1M / 396M INFO General (launcher.cpp : 418) Creating main extenders, unique edge length = 2000 0:00:06.047 1M / 396M INFO General (launcher.cpp : 342) filling path container 0:00:06.047 1M / 396M INFO General (extenders_logic.cpp : 345) Creating extender; library index size: 2 0:00:06.047 1M / 396M INFO General (extenders_logic.cpp : 345) Creating extender; library index size: 2 0:00:06.047 1M / 396M INFO General (extenders_logic.cpp : 47) resolvable_repeat_length_bound set to 10000 0:00:06.047 1M / 396M INFO General (extenders_logic.cpp : 543) Using 1 paired-end library 0:00:06.047 1M / 396M INFO General (extenders_logic.cpp : 544) Using 1 paired-end scaffolding library 0:00:06.047 1M / 396M INFO General (extenders_logic.cpp : 545) Using 1 single read library 0:00:06.047 1M / 396M INFO General (launcher.cpp : 385) Filling backbone edges for long reads scaffolding... 0:00:06.047 1M / 396M INFO General (launcher.cpp : 387) with long reads paths 0:00:06.047 1M / 396M INFO General (launcher.cpp : 396) Removing fake unique with paired-end libs 0:00:06.048 1M / 396M INFO General (launcher.cpp : 407) 0 unique edges 0:00:06.048 1M / 396M INFO General (extenders_logic.cpp : 446) Using 0 long reads scaffolding libraries 0:00:06.048 1M / 396M INFO General (extenders_logic.cpp : 456) Using additional coordinated coverage extender 0:00:06.048 1M / 396M INFO General (launcher.cpp : 447) Total number of extenders is 5 0:00:06.048 1M / 396M INFO General (launcher.cpp : 250) Finalizing paths 0:00:06.048 1M / 396M INFO General (launcher.cpp : 252) Deduplicating paths 0:00:06.048 1M / 396M INFO General (launcher.cpp : 256) Paths deduplicated 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 60) Removing overlaps 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 70) Marking overlaps 0:00:06.048 1M / 396M INFO OverlapRemover (overlap_remover.hpp : 116) Marking start/end overlaps 0:00:06.048 1M / 396M INFO OverlapRemover (overlap_remover.hpp : 119) Marking remaining overlaps 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 73) Splitting paths 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 78) Deduplicating paths 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 80) Overlaps removed 0:00:06.048 1M / 396M INFO General (launcher.cpp : 273) Paths finalized 0:00:06.048 1M / 396M INFO General (launcher.cpp : 454) Closing gaps in paths 0:00:06.048 1M / 396M INFO General (launcher.cpp : 484) Gap closing completed 0:00:06.048 1M / 396M INFO General (launcher.cpp : 302) Traversing tandem repeats 0:00:06.048 1M / 396M INFO General (launcher.cpp : 312) Traversed 0 loops 0:00:06.048 1M / 396M INFO General (launcher.cpp : 250) Finalizing paths 0:00:06.048 1M / 396M INFO General (launcher.cpp : 252) Deduplicating paths 0:00:06.048 1M / 396M INFO General (launcher.cpp : 256) Paths deduplicated 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 60) Removing overlaps 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 70) Marking overlaps 0:00:06.048 1M / 396M INFO OverlapRemover (overlap_remover.hpp : 116) Marking start/end overlaps 0:00:06.048 1M / 396M INFO OverlapRemover (overlap_remover.hpp : 119) Marking remaining overlaps 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 73) Splitting paths 0:00:06.048 1M / 396M INFO PEResolver (pe_resolver.cpp : 78) Deduplicating paths 0:00:06.049 1M / 396M INFO PEResolver (pe_resolver.cpp : 80) Overlaps removed 0:00:06.049 1M / 396M INFO General (launcher.cpp : 273) Paths finalized 0:00:06.049 1M / 396M INFO General (launcher.cpp : 664) ExSPAnder repeat resolving tool finished 0:00:06.049 1M / 396M INFO StageManager (stage.cpp : 185) STAGE == Contig Output (id: contig_output) 0:00:06.049 1M / 396M INFO General (contig_output.hpp : 16) Outputting contigs to /corral4/main/jobs/044/273/44273407/working/output/K55/before_rr.fasta 0:00:06.061 1M / 396M INFO General (contig_output_stage.cpp : 151) Writing GFA graph to /corral4/main/jobs/044/273/44273407/working/output/K55/assembly_graph_with_scaffolds.gfa 0:00:06.061 1M / 396M INFO General (contig_output_stage.cpp : 165) Outputting FastG graph to /corral4/main/jobs/044/273/44273407/working/output/K55/assembly_graph.fastg 0:00:06.082 1M / 396M INFO General (contig_output_stage.cpp : 196) Breaking scaffolds 0:00:06.082 1M / 396M INFO General (contig_output_stage.cpp : 98) Outputting contigs to /corral4/main/jobs/044/273/44273407/working/output/K55/final_contigs.fasta 0:00:06.093 1M / 396M INFO General (contig_output_stage.cpp : 104) Outputting FastG paths to /corral4/main/jobs/044/273/44273407/working/output/K55/final_contigs.paths 0:00:06.097 1M / 396M INFO General (contig_output_stage.cpp : 98) Outputting contigs to /corral4/main/jobs/044/273/44273407/working/output/K55/scaffolds.fasta 0:00:06.101 1M / 396M INFO General (contig_output_stage.cpp : 104) Outputting FastG paths to /corral4/main/jobs/044/273/44273407/working/output/K55/scaffolds.paths 0:00:06.107 1M / 396M INFO General (contig_output_stage.cpp : 111) Populating GFA with scaffold paths 0:00:06.113 1M / 396M INFO General (pipeline.cpp : 287) SPAdes finished 0:00:06.113 1M / 396M INFO General (main.cpp : 136) Assembling time: 0 hours 0 minutes 6 seconds ===== K55 finished. ===== Copy files started. == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/copy_files.py /corral4/main/jobs/044/273/44273407/working/output/K55/before_rr.fasta /corral4/main/jobs/044/273/44273407/working/output/before_rr.fasta /corral4/main/jobs/044/273/44273407/working/output/K55/assembly_graph_after_simplification.gfa /corral4/main/jobs/044/273/44273407/working/output/assembly_graph_after_simplification.gfa /corral4/main/jobs/044/273/44273407/working/output/K55/final_contigs.fasta /corral4/main/jobs/044/273/44273407/working/output/contigs.fasta /corral4/main/jobs/044/273/44273407/working/output/K55/first_pe_contigs.fasta /corral4/main/jobs/044/273/44273407/working/output/first_pe_contigs.fasta /corral4/main/jobs/044/273/44273407/working/output/K55/strain_graph.gfa /corral4/main/jobs/044/273/44273407/working/output/strain_graph.gfa /corral4/main/jobs/044/273/44273407/working/output/K55/scaffolds.fasta /corral4/main/jobs/044/273/44273407/working/output/scaffolds.fasta /corral4/main/jobs/044/273/44273407/working/output/K55/scaffolds.paths /corral4/main/jobs/044/273/44273407/working/output/scaffolds.paths /corral4/main/jobs/044/273/44273407/working/output/K55/assembly_graph_with_scaffolds.gfa /corral4/main/jobs/044/273/44273407/working/output/assembly_graph_with_scaffolds.gfa /corral4/main/jobs/044/273/44273407/working/output/K55/assembly_graph.fastg /corral4/main/jobs/044/273/44273407/working/output/assembly_graph.fastg /corral4/main/jobs/044/273/44273407/working/output/K55/final_contigs.paths /corral4/main/jobs/044/273/44273407/working/output/contigs.paths ===== Copy files finished. ===== Assembling finished. ===== Breaking scaffolds started. == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/breaking_scaffolds_script.py --result_scaffolds_filename /corral4/main/jobs/044/273/44273407/working/output/scaffolds.fasta --misc_dir /corral4/main/jobs/044/273/44273407/working/output/misc --threshold_for_breaking_scaffolds 3 ===== Breaking scaffolds finished. ===== Terminate started. ===== Terminate finished. * Corrected reads are in /corral4/main/jobs/044/273/44273407/working/output/corrected/ * Assembled contigs are in /corral4/main/jobs/044/273/44273407/working/output/contigs.fasta * Assembled scaffolds are in /corral4/main/jobs/044/273/44273407/working/output/scaffolds.fasta * Paths in the assembly graph corresponding to the contigs are in /corral4/main/jobs/044/273/44273407/working/output/contigs.paths * Paths in the assembly graph corresponding to the scaffolds are in /corral4/main/jobs/044/273/44273407/working/output/scaffolds.paths * Assembly graph is in /corral4/main/jobs/044/273/44273407/working/output/assembly_graph.fastg * Assembly graph in GFA format is in /corral4/main/jobs/044/273/44273407/working/output/assembly_graph_with_scaffolds.gfa ======= SPAdes pipeline finished. SPAdes log can be found here: /corral4/main/jobs/044/273/44273407/working/output/spades.log Thank you for using SPAdes! ``` **Job Parameters:** * | Job parameter | Parameter value | | ------------- | --------------- | | singlePaired | ` {"__current_case__": 1, "input1": {"values": [{"id": 99730755, "src": "hda"}]}, "orientation": "fr", "sPaired": "paired_interlaced", "type_paired": "pe"} ` | | library\_number | ` "true" ` | | additional\_reads | ` {"__current_case__": 1, "selector": "false"} ` | | arf | ` {"nanopore": null, "pacbio": null} ` | | kmer\_cond | ` {"__current_case__": 0, "kmer_sel": "auto"} ` | | phred\_offset | ` "auto" ` | | mode\_sel | ` None ` | | optional\_output | ` ["ag", "ags", "cn", "sc"] ` | | \_\_job\_resource | ` {"__current_case__": 0, "__job_resource__select": "no"} ` | | chromInfo | ` "/cvmfs/data.galaxyproject.org/managed/len/ucsc/?.len" ` | | dbkey | ` "?" ` | | \_\_input\_ext | ` "input" ` |

• ✅ toolshed.g2.bx.psu.edu/repos/nml/metaspades/metaspades (Test #2)

  **Command Line:** * ```console ``` **Exit Code:** * ```console 0 ``` **Standard Output:** * ```console Command line: /usr/local/bin/metaspades.py -o /jetstream2/scratch/main/jobs/44273448/working/output -t 8 -m 29 --pe-1 1 /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz --pe-2 1 /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz --pe-or 1 fr System information: SPAdes version: 3.15.3 Python version: 3.8.12 OS: Linux-5.18.5-1.el8.elrepo.x86_64-x86_64-with-glibc2.10 Output dir: /jetstream2/scratch/main/jobs/44273448/working/output Mode: read error correction and assembling Debug mode is turned OFF Dataset parameters: Metagenomic mode Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz'] right reads: ['/jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz'] interlaced reads: not specified single reads: not specified merged reads: not specified Read error correction parameters: Iterations: 1 PHRED offset will be auto-detected Corrected reads will be compressed Assembly parameters: k: [21, 33, 55] Repeat resolution is enabled Mismatch careful mode is turned OFF MismatchCorrector will be SKIPPED Coverage cutoff is turned OFF Other parameters: Dir for temp files: /jetstream2/scratch/main/jobs/44273448/working/output/tmp Threads: 8 Memory limit (in Gb): 29 ======= SPAdes pipeline started. Log can be found here: /jetstream2/scratch/main/jobs/44273448/working/output/spades.log /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz: max reads length: 100 /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz: max reads length: 100 Reads length: 100 ===== Before start started. ===== Read error correction started. ===== Read error correction started. == Running: /usr/local/bin/spades-hammer /jetstream2/scratch/main/jobs/44273448/working/output/corrected/configs/config.info 0:00:00.000 1M / 19M INFO General (main.cpp : 75) Starting BayesHammer, built from N/A, git revision N/A 0:00:00.016 1M / 19M INFO General (main.cpp : 76) Loading config from /jetstream2/scratch/main/jobs/44273448/working/output/corrected/configs/config.info 0:00:00.031 1M / 19M INFO General (main.cpp : 78) Maximum # of threads to use (adjusted due to OMP capabilities): 8 0:00:00.051 1M / 19M INFO General (memory_limit.cpp : 48) Memory limit set to 29 Gb 0:00:00.067 1M / 19M INFO General (main.cpp : 86) Trying to determine PHRED offset 0:00:00.083 1M / 19M INFO General (main.cpp : 92) Determined value is 33 0:00:00.099 1M / 19M INFO General (hammer_tools.cpp : 38) Hamming graph threshold tau=1, k=21, subkmer positions = [ 0 10 ] 0:00:00.114 1M / 19M INFO General (main.cpp : 113) Size of aux. kmer data 24 bytes === ITERATION 0 begins === 0:00:00.130 1M / 19M INFO K-mer Counting (kmer_data.cpp : 283) Estimating k-mer count 0:00:00.172 129M / 151M INFO K-mer Counting (kmer_data.cpp : 288) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz 0:00:00.205 129M / 151M INFO K-mer Counting (kmer_data.cpp : 288) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz 0:00:00.245 129M / 151M INFO K-mer Counting (kmer_data.cpp : 302) Total 4108 reads processed 0:00:00.787 129M / 151M INFO K-mer Counting (kmer_data.cpp : 305) Estimated 2171 distinct kmers 0:00:00.795 1M / 151M INFO K-mer Counting (kmer_data.cpp : 309) Filtering singleton k-mers 0:00:00.803 1M / 151M INFO K-mer Counting (kmer_data.cpp : 315) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz 0:00:01.105 1M / 151M INFO K-mer Counting (kmer_data.cpp : 315) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz 0:00:01.447 1M / 151M INFO K-mer Counting (kmer_data.cpp : 329) Total 4108 reads processed 0:00:01.463 1M / 151M INFO General (kmer_index_builder.hpp : 243) Splitting kmer instances into 16 files using 8 threads. This might take a while. 0:00:01.473 1M / 151M INFO General (file_limit.hpp : 32) Open file limit set to 131072 0:00:01.502 1M / 151M INFO General (kmer_splitter.hpp : 93) Memory available for splitting buffers: 1.20833 Gb 0:00:01.518 1M / 151M INFO General (kmer_splitter.hpp : 101) Using cell size of 4194304 0:00:01.566 4609M / 4609M INFO K-mer Splitting (kmer_data.cpp : 97) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz 0:00:01.621 4609M / 4609M INFO K-mer Splitting (kmer_data.cpp : 97) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz 0:00:01.681 4609M / 4609M INFO K-mer Splitting (kmer_data.cpp : 112) Total 4108 reads processed 0:00:01.689 1M / 446M INFO General (kmer_index_builder.hpp : 249) Starting k-mer counting. 0:00:01.724 1M / 446M INFO General (kmer_index_builder.hpp : 260) K-mer counting done. There are 1974 kmers in total. 0:00:01.752 1M / 446M INFO K-mer Index Building (kmer_index_builder.hpp : 395) Building perfect hash indices 0:00:01.781 1M / 446M INFO K-mer Index Building (kmer_index_builder.hpp : 431) Index built. Total 1974 kmers, 13944 bytes occupied (56.5106 bits per kmer). 0:00:01.796 1M / 446M INFO K-mer Counting (kmer_data.cpp : 354) Arranging kmers in hash map order 0:00:01.844 1M / 446M INFO General (main.cpp : 148) Clustering Hamming graph. 0:00:01.890 1M / 446M INFO General (main.cpp : 155) Extracting clusters: 0:00:01.905 1M / 446M INFO General (concurrent_dsu.cpp : 18) Connecting to root 0:00:01.937 1M / 446M INFO General (concurrent_dsu.cpp : 34) Calculating counts 0:00:01.968 1M / 446M INFO General (concurrent_dsu.cpp : 63) Writing down entries 0:00:01.993 1M / 446M INFO General (main.cpp : 167) Clustering done. Total clusters: 1960 0:00:02.001 1M / 446M INFO K-mer Counting (kmer_data.cpp : 371) Collecting K-mer information, this takes a while. 0:00:02.017 1M / 446M INFO K-mer Counting (kmer_data.cpp : 377) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz 0:00:02.069 1M / 446M INFO K-mer Counting (kmer_data.cpp : 377) Processing /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz 0:00:02.122 1M / 446M INFO K-mer Counting (kmer_data.cpp : 384) Collection done, postprocessing. 0:00:02.137 1M / 446M INFO K-mer Counting (kmer_data.cpp : 397) There are 1974 kmers in total. Among them 0 (0%) are singletons. 0:00:02.153 1M / 446M INFO General (main.cpp : 173) Subclustering Hamming graph 0:00:02.187 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 650) Subclustering done. Total 0 non-read kmers were generated. 0:00:02.201 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 651) Subclustering statistics: 0:00:02.216 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 652) Total singleton hamming clusters: 1946. Among them 1946 (100%) are good 0:00:02.232 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 653) Total singleton subclusters: 8. Among them 8 (100%) are good 0:00:02.247 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 654) Total non-singleton subcluster centers: 10. Among them 10 (100%) are good 0:00:02.263 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 655) Average size of non-trivial subcluster: 2.8 kmers 0:00:02.278 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 656) Average number of sub-clusters per non-singleton cluster: 1.28571 0:00:02.294 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 657) Total solid k-mers: 1964 0:00:02.309 1M / 446M INFO Hamming Subclustering (kmer_cluster.cpp : 658) Substitution probabilities: [4,4]((0.875,0.125,0,0),(0,1,0,0),(0,0,1,0),(0,0,0.125,0.875)) 0:00:02.325 1M / 446M INFO General (main.cpp : 178) Finished clustering. 0:00:02.340 1M / 446M INFO General (main.cpp : 197) Starting solid k-mers expansion in 8 threads. 0:00:02.401 1M / 446M INFO General (main.cpp : 218) Solid k-mers iteration 0 produced 0 new k-mers. 0:00:02.417 1M / 446M INFO General (main.cpp : 222) Solid k-mers finalized 0:00:02.432 1M / 446M INFO General (hammer_tools.cpp : 222) Starting read correction in 8 threads. 0:00:02.448 1M / 446M INFO General (hammer_tools.cpp : 235) Correcting pair of reads: /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_1.fastq.gz.fastq.gz and /jetstream2/scratch/main/jobs/44273448/working/paired_reads1/ecoli_1K_2.fastq.gz.fastq.gz 0:00:02.502 179M / 446M INFO General (hammer_tools.cpp : 170) Prepared batch 0 of 2054 reads. 0:00:02.525 179M / 446M INFO General (hammer_tools.cpp : 177) Processed batch 0 0:00:02.529 179M / 446M INFO General (hammer_tools.cpp : 187) Written batch 0 0:00:02.539 1M / 446M INFO General (hammer_tools.cpp : 276) Correction done. Changed 4 bases in 4 reads. 0:00:02.540 1M / 446M INFO General (hammer_tools.cpp : 277) Failed to correct 0 bases out of 353915. 0:00:02.540 1M / 446M INFO General (main.cpp : 255) Saving corrected dataset description to /jetstream2/scratch/main/jobs/44273448/working/output/corrected/corrected.yaml 0:00:02.540 1M / 446M INFO General (main.cpp : 262) All done. Exiting. ===== Read error correction finished. ===== corrected reads compression started. == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/compress_all.py --input_file /jetstream2/scratch/main/jobs/44273448/working/output/corrected/corrected.yaml --ext_python_modules_home /usr/local/share/spades --max_threads 8 --output_dir /jetstream2/scratch/main/jobs/44273448/working/output/corrected --gzip_output == Compressing corrected reads (with gzip) == Files to compress: ['/jetstream2/scratch/main/jobs/44273448/working/output/corrected/ecoli_1K_1.fastq.gz.fastq.00.0_0.cor.fastq', '/jetstream2/scratch/main/jobs/44273448/working/output/corrected/ecoli_1K_2.fastq.gz.fastq.00.0_0.cor.fastq', '/jetstream2/scratch/main/jobs/44273448/working/output/corrected/ecoli_1K__unpaired.00.0_0.cor.fastq'] == Files compression is finished == Dataset yaml file is updated ===== corrected reads compression finished. ===== Read error correction finished. ===== Assembling started. ===== K21 started. == Running: /usr/local/bin/spades-core /jetstream2/scratch/main/jobs/44273448/working/output/K21/configs/config.info /jetstream2/scratch/main/jobs/44273448/working/output/K21/configs/mda_mode.info /jetstream2/scratch/main/jobs/44273448/working/output/K21/configs/meta_mode.info 0:00:00.000 1M / 19M INFO General (main.cpp : 99) Loaded config from /jetstream2/scratch/main/jobs/44273448/working/output/K21/configs/config.info 0:00:00.020 1M / 19M INFO General (main.cpp : 99) Loaded config from /jetstream2/scratch/main/jobs/44273448/working/output/K21/configs/mda_mode.info 0:00:00.030 1M / 19M INFO General (main.cpp : 99) Loaded config from /jetstream2/scratch/main/jobs/44273448/working/output/K21/configs/meta_mode.info 0:00:00.047 1M / 19M INFO General (memory_limit.cpp : 48) Memory limit set to 29 Gb 0:00:00.067 1M / 19M INFO General (main.cpp : 107) Starting SPAdes, built from N/A, git revision N/A 0:00:00.083 1M / 19M INFO General (main.cpp : 108) Maximum k-mer length: 128 0:00:00.098 1M / 19M INFO General (main.cpp : 109) Assembling dataset (/jetstream2/scratch/main/jobs/44273448/working/output/dataset.info) with K=21 0:00:00.115 1M / 19M INFO General (main.cpp : 110) Maximum # of threads to use (adjusted due to OMP capabilities): 8 0:00:00.131 1M / 19M INFO General (pipeline.cpp : 212) SPAdes started 0:00:00.146 1M / 19M INFO General (pipeline.cpp : 225) Starting from stage: read_conversion 0:00:00.162 1M / 19M INFO General (pipeline.cpp : 231) Two-step repeat resolution disabled 0:00:00.188 1M / 19M INFO GraphCore (graph_core.hpp : 672) Graph created, vertex min_id: 3, edge min_id: 3 0:00:00.203 1M / 19M INFO GraphCore (graph_core.hpp : 673) Vertex size: 48, edge size: 40 0:00:00.220 1M / 19M INFO General (edge_index.hpp : 113) Size of edge index entries: 12/8 0:00:00.238 1M / 19M INFO StageManager (stage.cpp : 185) STAGE == Binary Read Conversion (id: read_conversion) 0:00:00.255 1M / 19M INFO General (read_converter.cpp : 72) Converting reads to binary format for library #0 (takes a while) 0:00:00.270 1M / 19M INFO General (read_converter.cpp : 73) Converting paired reads 0:00:00.303 63M / 63M INFO General (binary_converter.cpp : 111) 2054 reads written 0:00:00.319 41M / 41M INFO General (read_converter.cpp : 86) Converting single reads 0:00:00.336 71M / 71M INFO General (binary_converter.cpp : 111) 0 reads written 0:00:00.352 61M / 61M INFO General (read_converter.cpp : 92) Converting merged reads 0:00:00.367 71M / 71M INFO General (binary_converter.cpp : 111) 0 reads written 0:00:00.386 1M / 25M INFO StageManager (stage.cpp : 185) STAGE == de Bruijn graph construction (id: construction) 0:00:00.403 1M / 25M INFO General (construction.cpp : 153) Max read length 100 0:00:00.419 1M / 25M INFO General (construction.cpp : 159) Average read length 86 .. ing/output/K55/before_rr.fasta 0:00:02.228 1M / 1318M INFO General (contig_output_stage.cpp : 151) Writing GFA graph to /jetstream2/scratch/main/jobs/44273448/working/output/K55/assembly_graph_after_simplification.gfa 0:00:02.228 1M / 1318M INFO StageManager (stage.cpp : 185) STAGE == Paired Information Counting (id: late_pair_info_count) 0:00:02.228 1M / 1318M INFO General (graph_pack.cpp : 77) Normalizing k-mer map. Total 0 kmers to process 0:00:02.228 1M / 1318M INFO General (graph_pack.cpp : 79) Normalizing done 0:00:02.228 1M / 1318M INFO General (pair_info_count.cpp : 339) Min edge length for estimation: 900 0:00:02.229 1M / 1318M INFO General (pair_info_count.cpp : 350) Estimating insert size for library #0 0:00:02.229 1M / 1318M INFO General (pair_info_count.cpp : 202) Estimating insert size (takes a while) 0:00:02.241 145M / 1318M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:02.725 145M / 1318M INFO General (sequence_mapper_notifier.h: 95) Total 2054 reads processed 0:00:02.840 145M / 1318M INFO General (pair_info_count.cpp : 220) Edge pairs: 2 0:00:02.841 145M / 1318M INFO General (pair_info_count.cpp : 222) 1636 paired reads (79.6495% of all) aligned to long edges 0:00:02.841 1M / 1318M INFO General (pair_info_count.cpp : 369) Insert size = 214.696, deviation = 10.4821, left quantile = 201, right quantile = 228, read length = 100 0:00:02.841 1M / 1318M INFO General (pair_info_count.cpp : 390) Filtering data for library #0 0:00:02.841 1M / 1318M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:02.842 1M / 1318M INFO General (sequence_mapper_notifier.h: 95) Total 2054 reads processed 0:00:02.842 1M / 1318M INFO General (pair_info_count.cpp : 402) Mapping library #0 0:00:02.842 1M / 1318M INFO General (pair_info_count.cpp : 404) Mapping paired reads (takes a while) 0:00:02.842 1M / 1318M INFO General (pair_info_count.cpp : 299) Left insert size quantile 201, right insert size quantile 228, filtering threshold 1, rounding threshold 0 0:00:02.846 10M / 1318M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:02.852 10M / 1318M INFO General (sequence_mapper_notifier.h: 95) Total 2054 reads processed 0:00:02.854 1M / 1318M INFO General (pair_info_count.cpp : 346) Mapping contigs library #1 0:00:02.863 1M / 1318M INFO General (pair_info_count.cpp : 48) Selecting usual mapper 0:00:02.872 1M / 1318M INFO General (sequence_mapper_notifier.h: 95) Total 1 reads processed 0:00:02.873 1M / 1318M INFO StageManager (stage.cpp : 185) STAGE == Distance Estimation (id: distance_estimation) 0:00:02.873 1M / 1318M INFO General (distance_estimation.cpp : 179) Processing library #0 0:00:02.873 1M / 1318M INFO General (distance_estimation.cpp : 150) Weight Filter Done 0:00:02.873 1M / 1318M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 0:00:02.873 1M / 1318M INFO General (distance_estimation.cpp : 37) Filtering info 0:00:02.873 1M / 1318M INFO General (pair_info_filters.hpp : 242) Start filtering; library index size: 2 0:00:02.873 1M / 1318M INFO General (pair_info_filters.hpp : 263) Done filtering; library index size: 2 0:00:02.873 1M / 1318M INFO General (distance_estimation.cpp : 156) Refining clustered pair information 0:00:02.873 1M / 1318M INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 0:00:02.873 1M / 1318M INFO General (distance_estimation.cpp : 160) Improving paired information 0:00:02.874 1M / 1318M INFO PairInfoImprover (pair_info_improver.hpp : 104) Paired info stats: missing = 0; contradictional = 0 0:00:02.874 1M / 1318M INFO PairInfoImprover (pair_info_improver.hpp : 104) Paired info stats: missing = 0; contradictional = 0 0:00:02.874 1M / 1318M INFO General (distance_estimation.cpp : 104) Filling scaffolding index 0:00:02.874 1M / 1318M INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator 0:00:02.875 1M / 1318M INFO General (distance_estimation.cpp : 37) Filtering info 0:00:02.875 1M / 1318M INFO General (pair_info_filters.hpp : 242) Start filtering; library index size: 2 0:00:02.875 1M / 1318M INFO General (pair_info_filters.hpp : 263) Done filtering; library index size: 2 0:00:02.875 1M / 1318M INFO General (distance_estimation.cpp : 186) Clearing raw paired index 0:00:02.875 1M / 1318M INFO StageManager (stage.cpp : 185) STAGE == Repeat Resolving (id: repeat_resolving) 0:00:02.875 1M / 1318M INFO General (repeat_resolving.cpp : 87) Using Path-Extend repeat resolving 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 600) ExSPAnder repeat resolving tool started 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 418) Creating main extenders, unique edge length = 2000 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 342) filling path container 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 345) Creating extender; library index size: 2 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 345) Creating extender; library index size: 2 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 47) resolvable_repeat_length_bound set to 10000 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 543) Using 1 paired-end library 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 544) Using 1 paired-end scaffolding library 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 545) Using 1 single read library 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 385) Filling backbone edges for long reads scaffolding... 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 387) with long reads paths 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 396) Removing fake unique with paired-end libs 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 407) 0 unique edges 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 446) Using 0 long reads scaffolding libraries 0:00:02.875 1M / 1318M INFO General (extenders_logic.cpp : 456) Using additional coordinated coverage extender 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 447) Total number of extenders is 5 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 250) Finalizing paths 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 252) Deduplicating paths 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 256) Paths deduplicated 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 60) Removing overlaps 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 70) Marking overlaps 0:00:02.875 1M / 1318M INFO OverlapRemover (overlap_remover.hpp : 116) Marking start/end overlaps 0:00:02.875 1M / 1318M INFO OverlapRemover (overlap_remover.hpp : 119) Marking remaining overlaps 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 73) Splitting paths 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 78) Deduplicating paths 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 80) Overlaps removed 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 273) Paths finalized 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 454) Closing gaps in paths 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 484) Gap closing completed 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 302) Traversing tandem repeats 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 312) Traversed 0 loops 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 250) Finalizing paths 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 252) Deduplicating paths 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 256) Paths deduplicated 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 60) Removing overlaps 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 70) Marking overlaps 0:00:02.875 1M / 1318M INFO OverlapRemover (overlap_remover.hpp : 116) Marking start/end overlaps 0:00:02.875 1M / 1318M INFO OverlapRemover (overlap_remover.hpp : 119) Marking remaining overlaps 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 73) Splitting paths 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 78) Deduplicating paths 0:00:02.875 1M / 1318M INFO PEResolver (pe_resolver.cpp : 80) Overlaps removed 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 273) Paths finalized 0:00:02.875 1M / 1318M INFO General (launcher.cpp : 664) ExSPAnder repeat resolving tool finished 0:00:02.875 1M / 1318M INFO StageManager (stage.cpp : 185) STAGE == Contig Output (id: contig_output) 0:00:02.875 1M / 1318M INFO General (contig_output.hpp : 16) Outputting contigs to /jetstream2/scratch/main/jobs/44273448/working/output/K55/before_rr.fasta 0:00:02.884 1M / 1318M INFO General (contig_output_stage.cpp : 151) Writing GFA graph to /jetstream2/scratch/main/jobs/44273448/working/output/K55/assembly_graph_with_scaffolds.gfa 0:00:02.885 1M / 1318M INFO General (contig_output_stage.cpp : 165) Outputting FastG graph to /jetstream2/scratch/main/jobs/44273448/working/output/K55/assembly_graph.fastg 0:00:02.893 1M / 1318M INFO General (contig_output_stage.cpp : 196) Breaking scaffolds 0:00:02.893 1M / 1318M INFO General (contig_output_stage.cpp : 98) Outputting contigs to /jetstream2/scratch/main/jobs/44273448/working/output/K55/final_contigs.fasta 0:00:02.901 1M / 1318M INFO General (contig_output_stage.cpp : 104) Outputting FastG paths to /jetstream2/scratch/main/jobs/44273448/working/output/K55/final_contigs.paths 0:00:02.910 1M / 1318M INFO General (contig_output_stage.cpp : 98) Outputting contigs to /jetstream2/scratch/main/jobs/44273448/working/output/K55/scaffolds.fasta 0:00:02.917 1M / 1318M INFO General (contig_output_stage.cpp : 104) Outputting FastG paths to /jetstream2/scratch/main/jobs/44273448/working/output/K55/scaffolds.paths 0:00:02.925 1M / 1318M INFO General (contig_output_stage.cpp : 111) Populating GFA with scaffold paths 0:00:02.933 1M / 1318M INFO General (pipeline.cpp : 287) SPAdes finished 0:00:02.935 1M / 1318M INFO General (main.cpp : 136) Assembling time: 0 hours 0 minutes 2 seconds ===== K55 finished. ===== Copy files started. == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/copy_files.py /jetstream2/scratch/main/jobs/44273448/working/output/K55/before_rr.fasta /jetstream2/scratch/main/jobs/44273448/working/output/before_rr.fasta /jetstream2/scratch/main/jobs/44273448/working/output/K55/assembly_graph_after_simplification.gfa /jetstream2/scratch/main/jobs/44273448/working/output/assembly_graph_after_simplification.gfa /jetstream2/scratch/main/jobs/44273448/working/output/K55/final_contigs.fasta /jetstream2/scratch/main/jobs/44273448/working/output/contigs.fasta /jetstream2/scratch/main/jobs/44273448/working/output/K55/first_pe_contigs.fasta /jetstream2/scratch/main/jobs/44273448/working/output/first_pe_contigs.fasta /jetstream2/scratch/main/jobs/44273448/working/output/K55/strain_graph.gfa /jetstream2/scratch/main/jobs/44273448/working/output/strain_graph.gfa /jetstream2/scratch/main/jobs/44273448/working/output/K55/scaffolds.fasta /jetstream2/scratch/main/jobs/44273448/working/output/scaffolds.fasta /jetstream2/scratch/main/jobs/44273448/working/output/K55/scaffolds.paths /jetstream2/scratch/main/jobs/44273448/working/output/scaffolds.paths /jetstream2/scratch/main/jobs/44273448/working/output/K55/assembly_graph_with_scaffolds.gfa /jetstream2/scratch/main/jobs/44273448/working/output/assembly_graph_with_scaffolds.gfa /jetstream2/scratch/main/jobs/44273448/working/output/K55/assembly_graph.fastg /jetstream2/scratch/main/jobs/44273448/working/output/assembly_graph.fastg /jetstream2/scratch/main/jobs/44273448/working/output/K55/final_contigs.paths /jetstream2/scratch/main/jobs/44273448/working/output/contigs.paths ===== Copy files finished. ===== Assembling finished. ===== Breaking scaffolds started. == Running: /usr/local/bin/python /usr/local/share/spades/spades_pipeline/scripts/breaking_scaffolds_script.py --result_scaffolds_filename /jetstream2/scratch/main/jobs/44273448/working/output/scaffolds.fasta --misc_dir /jetstream2/scratch/main/jobs/44273448/working/output/misc --threshold_for_breaking_scaffolds 3 ===== Breaking scaffolds finished. ===== Terminate started. ===== Terminate finished. * Corrected reads are in /jetstream2/scratch/main/jobs/44273448/working/output/corrected/ * Assembled contigs are in /jetstream2/scratch/main/jobs/44273448/working/output/contigs.fasta * Assembled scaffolds are in /jetstream2/scratch/main/jobs/44273448/working/output/scaffolds.fasta * Paths in the assembly graph corresponding to the contigs are in /jetstream2/scratch/main/jobs/44273448/working/output/contigs.paths * Paths in the assembly graph corresponding to the scaffolds are in /jetstream2/scratch/main/jobs/44273448/working/output/scaffolds.paths * Assembly graph is in /jetstream2/scratch/main/jobs/44273448/working/output/assembly_graph.fastg * Assembly graph in GFA format is in /jetstream2/scratch/main/jobs/44273448/working/output/assembly_graph_with_scaffolds.gfa ======= SPAdes pipeline finished. SPAdes log can be found here: /jetstream2/scratch/main/jobs/44273448/working/output/spades.log Thank you for using SPAdes! ``` **Job Parameters:** * | Job parameter | Parameter value | | ------------- | --------------- | | singlePaired | ` {"__current_case__": 0, "input1": {"values": [{"id": 99730754, "src": "hda"}]}, "input2": {"values": [{"id": 99730756, "src": "hda"}]}, "orientation": "fr", "sPaired": "paired", "type_paired": "pe"} ` | | library\_number | ` "true" ` | | additional\_reads | ` {"__current_case__": 1, "selector": "false"} ` | | arf | ` {"nanopore": null, "pacbio": null} ` | | kmer\_cond | ` {"__current_case__": 0, "kmer_sel": "auto"} ` | | phred\_offset | ` "auto" ` | | mode\_sel | ` None ` | | optional\_output | ` ["ag", "ags", "cn", "sc"] ` | | \_\_job\_resource | ` {"__current_case__": 0, "__job_resource__select": "no"} ` | | chromInfo | ` "/cvmfs/data.galaxyproject.org/managed/len/ucsc/?.len" ` | | dbkey | ` "?" ` | | \_\_input\_ext | ` "input" ` |