Loading...
• Velvet
Current version 1.2.10
Source code in C language
https://www.ebi.ac.uk/~zerbino/velvet/
• VelvetOptimiser
Current version 2.2.5
Perl script
Requirements
• Velvet >= 0.7.51 (including 1.x series) : Velvet 1.2.10
• Perl >= 5.8
• BioPerl >= 1.4
http://www.vicbioinformatics.com/software.velvetoptimiser.shtml
• SPAdes
Current version 3.12
Executable files (Linux 64 bits and MacOSx) and Source code
http://cab.spbu.ru/software/spades/
• MaSuRCA
Current version 3.2.8
Source code in C language
https://github.com/alekseyzimin/masurca
Use a part of Chr11 of Solanum lycopersicum (Tomato)
Chr11 ~53 Mbp -> ~ 4.8 Mbp
Generate simulated illumina Paired-end FASTQ files
Location : /home/chumpol/AssemblyWS
• FASTA -> Reference sequence in FASTA formatted (cabV2.fa)
• FASTQ -> illumina paired-end reads in FASTQ formatted (cabV2_read1.fq.gz, cabV2_read2.fq.gz)
ssh annotest@158.108.144.7
mkdir AssemblyWS
dirWS = "/home/annotest/AssemblyWS"
cd {dirWS}
/home/annotest/AssemblyWS
%%bash
ln -s /home/chumpol/AssemblyWS/FASTQ .
%%bash
ln -s /home/chumpol/AssemblyWS/FASTA .
ls -l
total 0 lrwxrwxrwx 1 jupyterhub1 jupyterhub1 30 Aug 7 15:52 FASTA -> /home/chumpol/AssemblyWS/FASTA/ lrwxrwxrwx 1 jupyterhub1 jupyterhub1 30 Aug 7 15:52 FASTQ -> /home/chumpol/AssemblyWS/FASTQ/
%%bash
velveth
velveth - simple hashing program Version 1.2.10 Copyright 2007, 2008 Daniel Zerbino (zerbino@ebi.ac.uk) This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. Compilation settings: CATEGORIES = 6 MAXKMERLENGTH = 250 OPENMP LONGSEQUENCES BIGASSEMBLY Usage: ./velveth directory hash_length {[-file_format][-read_type][-separate|-interleaved] filename1 [filename2 ...]} {...} [options] directory : directory name for output files hash_length : EITHER an odd integer (if even, it will be decremented) <= 250 (if above, will be reduced) : OR: m,M,s where m and M are odd integers (if not, they will be decremented) with m < M <= 250 (if above, will be reduced) and s is a step (even number). Velvet will then hash from k=m to k=M with a step of s filename : path to sequence file or - for standard input File format options: -fasta -fastq -raw -fasta.gz -fastq.gz -raw.gz -sam -bam -fmtAuto (Note: -fmtAuto will detect fasta or fastq, and will try the following programs for decompression : gunzip, pbunzip2, bunzip2 File layout options for paired reads (only for fasta and fastq formats): -interleaved : File contains paired reads interleaved in the one file (default) -separate : Read 2 separate files for paired reads Read type options: -short -shortPaired ... -short5 -shortPaired5 -short6 -shortPaired6 -long -longPaired -reference Options: -strand_specific : for strand specific transcriptome sequencing data (default: off) -reuse_Sequences : reuse Sequences file (or link) already in directory (no need to provide original filenames in this case (default: off) -reuse_binary : reuse binary sequences file (or link) already in directory (no need to provide original filenames in this case (default: off) -noHash : simply prepare Sequences file, do not hash reads or prepare Roadmaps file (default: off) -create_binary : create binary CnyUnifiedSeq file (default: off) Synopsis: - Short single end reads: velveth Assem 29 -short -fastq s_1_sequence.txt - Paired-end short reads (remember to interleave paired reads): velveth Assem 31 -shortPaired -fasta interleaved.fna - Paired-end short reads (using separate files for the paired reads) velveth Assem 31 -shortPaired -fasta -separate left.fa right.fa - Two channels and some long reads: velveth Assem 43 -short -fastq unmapped.fna -longPaired -fasta SangerReads.fasta - Three channels: velveth Assem 35 -shortPaired -fasta pe_lib1.fasta -shortPaired2 pe_lib2.fasta -short3 se_lib1.fa Output: directory/Roadmaps directory/Sequences [Both files are picked up by graph, so please leave them there]
mkdir Velvet
dirVelvet = "/home/annotest/AssemblyWS/Velvet"
cd {dirVelvet}
/home/annotest/AssemblyWS/Velvet
%%bash
ln -s ../FASTQ/* .
ls -l
total 0 lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:00 cabV2_read1.fq.gz -> ../FASTQ/cabV2_read1.fq.gz lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:00 cabV2_read2.fq.gz -> ../FASTQ/cabV2_read2.fq.gz
%%bash
cp /home/chumpol/AssemblyWS/Velvet/Run_Velvet.sh .
%%bash
more Run_Velvet.sh
:::::::::::::: Run_Velvet.sh :::::::::::::: #!/bin/bash # $1 as k-mer # $2 input read velveth Test_${1} $1 -fastq.gz -shortPaired -separate ${2}_read1.fq.gz ${2}_read2.fq.gz velvetg Test_${1} -ins_length 300 -exp_cov 10 -cov_cutoff auto -min_contig_lgth 1000
k-mers : k-mers as first parameter ($1) of the script
-fastq.gz : format of read files
-shortPaired -separate : read type (Paired-end)
Filename : ${2} as second parameter of the script
-ins_length : expected distance between two paired-end reads (300)
-exp_cov : expected coverage to infer (10)
-cov_cutoff : removal of low coverage nodes (auto)
-min_contig_lgth : minimum contig length exported to contigs.fa file.
Output is saved in Test_${1}
%%bash
./Run_Velvet.sh 75 cabV2
[0.000000] Reading FastQ file cabV2_read1.fq.gz; [0.000291] Reading FastQ file cabV2_read2.fq.gz; [5.013386] 925060 sequences found in total in the paired sequence files [5.013390] Done [5.026487] Reading read set file Test_75/Sequences; [5.203390] 925060 sequences found [5.976033] Done [5.976037] 925060 sequences in total. [5.976143] Writing into roadmap file Test_75/Roadmaps... [6.359098] Inputting sequences... [6.365410] Inputting sequence 0 / 925060 [8.983243] === Sequences loaded in 2.624489 s [8.985614] Done inputting sequences [8.985616] Destroying splay table [9.372377] Splay table destroyed [0.000000] Reading roadmap file Test_75/Roadmaps [1.225080] 925060 roadmaps read [1.237108] Creating insertion markers [1.393650] Ordering insertion markers [1.419950] Counting preNodes [1.559739] 1677039 preNodes counted, creating them now [6.524007] Adjusting marker info... [6.661250] Connecting preNodes [7.019085] Cleaning up memory [7.020495] Done creating preGraph [7.020504] Concatenation... [7.563851] Renumbering preNodes [7.563894] Initial preNode count 1677039 [7.622448] Destroyed 1260839 preNodes [7.622453] Concatenation over! [7.622455] Clipping short tips off preGraph [7.739048] Concatenation... [7.911339] Renumbering preNodes [7.911342] Initial preNode count 416200 [7.916685] Destroyed 392546 preNodes [7.916687] Concatenation over! [7.916687] 199487 tips cut off [7.916688] 23654 nodes left [7.916800] Writing into pregraph file Test_75/PreGraph... [8.257118] Reading read set file Test_75/Sequences; [8.435761] 925060 sequences found [9.232938] Done [9.638351] Reading pre-graph file Test_75/PreGraph [9.638415] Graph has 23654 nodes and 925060 sequences [9.802831] Scanning pre-graph file Test_75/PreGraph for k-mers [9.957928] 5166917 kmers found [10.568908] Sorting kmer occurence table ... [15.315342] Sorting done. [15.315346] Computing acceleration table... [15.466536] Computing offsets... [15.604930] Ghost Threading through reads 0 / 925060 [16.031517] === Ghost-Threaded in 0.441526 s [16.031861] Threading through reads 0 / 925060 [17.042687] === Threaded in 1.011161 s [17.113997] Correcting graph with cutoff 0.200000 [17.117678] Determining eligible starting points [17.146119] Done listing starting nodes [17.146121] Initializing todo lists [17.149003] Done with initilization [17.149005] Activating arc lookup table [17.152900] Done activating arc lookup table [17.553726] 10000 / 23654 nodes visited [17.930653] 20000 / 23654 nodes visited [18.017725] Concatenation... [18.018440] Renumbering nodes [18.018441] Initial node count 23654 [18.018827] Removed 19478 null nodes [18.018832] Concatenation over! [18.018833] Clipping short tips off graph, drastic [18.019700] Concatenation... [18.043709] Renumbering nodes [18.043710] Initial node count 4176 [18.043861] Removed 1023 null nodes [18.043862] Concatenation over! [18.043862] 3153 nodes left [18.043953] Writing into graph file Test_75/Graph2... [18.666390] Measuring median coverage depth... [18.667539] Median coverage depth = 10.295438 [18.667582] Removing contigs with coverage < 5.147719... [18.669440] Concatenation... [18.714441] Renumbering nodes [18.714442] Initial node count 3153 [18.714514] Removed 2090 null nodes [18.714515] Concatenation over! [18.714555] Concatenation... [18.714631] Renumbering nodes [18.714631] Initial node count 1063 [18.714633] Removed 0 null nodes [18.714633] Concatenation over! [18.714640] Clipping short tips off graph, drastic [18.714741] Concatenation... [18.715255] Renumbering nodes [18.715256] Initial node count 1063 [18.715295] Removed 37 null nodes [18.715296] Concatenation over! [18.715296] 1026 nodes left [18.715297] Read coherency... [18.715305] Identifying unique nodes [18.715334] Done, 791 unique nodes counted [18.715335] Trimming read tips [18.715424] Renumbering nodes [18.715424] Initial node count 1026 [18.715426] Removed 0 null nodes [18.715426] Confronted to 0 multiple hits and 0 null over 0 [18.715427] Read coherency over! [18.722075] Starting pebble resolution... [18.732289] Computing read to node mapping array sizes [18.757604] Computing read to node mappings [18.768573] Estimating library insert lengths... [18.774250] Done [18.774260] Computing direct node to node mappings [18.788234] Scaffolding node 0 [18.798856] === Nodes Scaffolded in 0.024595 s [18.809034] Preparing to correct graph with cutoff 0.200000 [18.920196] Cleaning memory [18.920267] Deactivating local correction settings [18.920313] Pebble done. [18.920314] Starting pebble resolution... [18.929721] Computing read to node mapping array sizes [18.949847] Computing read to node mappings [18.962627] Estimating library insert lengths... [18.972112] Done [18.972119] Computing direct node to node mappings [18.993819] Scaffolding node 0 [19.005947] === Nodes Scaffolded in 0.033822 s [19.014262] Preparing to correct graph with cutoff 0.200000 [19.020280] Cleaning memory [19.020284] Deactivating local correction settings [19.020312] Pebble done. [19.020313] Concatenation... [19.029035] Renumbering nodes [19.029037] Initial node count 1026 [19.029114] Removed 631 null nodes [19.029123] Concatenation over! [19.029124] Removing reference contigs with coverage < 5.147719... [19.029158] Concatenation... [19.029170] Renumbering nodes [19.029171] Initial node count 395 [19.029172] Removed 0 null nodes [19.029178] Concatenation over! [19.034808] Writing contigs into Test_75/contigs.fa... [19.691495] Writing into stats file Test_75/stats.txt... [19.696405] Writing into graph file Test_75/LastGraph... [20.341936] Estimated Coverage cutoff = 5.147719 Final graph has 395 nodes and n50 of 55255, max 171853, total 4594714, using 860030/925060 reads
The final contigs.fa is saved in Test_75 directory.
Multi-threaded Perl script for automatically optimizing the three primary parameter options (K, -exp_cov, -cov_cutoff) for the Velvet assembler.
cd ..
/home/annotest/AssemblyWS
pwd
'/home/annotest/AssemblyWS'
mkdir VelvetOptimiser
cd VelvetOptimiser
/home/annotest/AssemblyWS/VelvetOptimiser
%%bash
ln -s ../FASTQ/* .
ls -l
total 0 lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:06 cabV2_read1.fq.gz -> ../FASTQ/cabV2_read1.fq.gz lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:06 cabV2_read2.fq.gz -> ../FASTQ/cabV2_read2.fq.gz
/home/chumpol/AssemblyWS/VelvetOptimiser/Run_VelvetOptimiser.sh
cp /home/chumpol/AssemblyWS/VelvetOptimiser/Run_VelvetOptimiser.sh .
cat Run_VelvetOptimiser.sh
#!/bin/env bash # $1 is number of threads # $2 is start k-mers # $3 is stop k-mers # $4 is read name # Start from $1 to $2, step 5 /share/apps/VelvetOptimiser/VelvetOptimiser.pl -t $1 -s $2 -e $3 -x 5 -f "-shortPaired -separate -fastq.gz ${4}_read1.fq.gz ${4}_read2.fq.gz" -o "-ins_length 300 -exp_cov 10 -cov_cutoff auto -min_contig_lgth 1000"
-t # : number of CPU threads to use
-s # : start k-mers
-e # : stop k-mers
-x # : incremental steps of k-mers
-f “string” : velveth parameters
-o “string” : velvetg parameters
%%bash
./Run_VelvetOptimiser.sh 16 85 91 cabV2
Logfile name: 07-08-2018-16-09-58_Logfile.txt
**************************************************** VelvetOptimiser.pl Version 2.3.0-alpha **************************************************** Number of CPUs available: 144 Current free RAM: 996.047GB Velvet OMP compiler setting: 1 Aug 7 16:09:58 Starting to check input parameters. Old hash step value 5 Hash search step value was odd, substracting one. New hash step value = 4 Velveth parameter string OK. Aug 7 16:09:58 Finished checking input parameters. Velvet details: Velvet version: 1.2.10 Compiled categories: 6 Compiled max kmer length: 250 Maximum number of Velvet instances to run: 16 Will run velvet optimiser with the following paramters: Velveth parameter string: -shortPaired -separate -fastq.gz cabV2_read1.fq.gz cabV2_read2.fq.gz Velveth start hash values: 85 Velveth end hash value: 91 Velveth hash step value: 4 Velvetg minimum coverage cutoff to use: 0 Read tracking for final assembly off. Aug 7 16:09:58 Beginning velveth runs. Aug 7 16:09:58 Running velveth with hash value: 85. Aug 7 16:10:00 Running velveth with hash value: 89. Aug 7 16:10:03 Running velveth with hash value: 91. Aug 7 16:10:09 Velveth with hash value 85 finished. Aug 7 16:10:10 Velveth with hash value 89 finished. Aug 7 16:10:13 Velveth with hash value 91 finished. Aug 7 16:10:13 Finished velveth runs. Aug 7 16:10:13 Beginning vanilla velvetg runs. Aug 7 16:10:13 Running vanilla velvetg on hash value: 85 Aug 7 16:10:15 Running vanilla velvetg on hash value: 89 Aug 7 16:10:18 Running vanilla velvetg on hash value: 91 Aug 7 16:10:35 Velvetg on hash value: 85 finished. Aug 7 16:10:36 Velvetg on hash value: 89 finished. Aug 7 16:10:37 Velvetg on hash value: 91 finished. Aug 7 16:10:37 Hash value of best assembly by assembly score: 91 Aug 7 16:10:37 Optimisation routine chosen for best assembly: shortPaired Aug 7 16:10:37 Looking for the expected coverage Aug 7 16:10:39 Expected coverage set to 7 Aug 7 16:10:39 Setting assembly short insert length(s) to auto Aug 7 16:10:39 Beginning coverage cutoff optimisation Aug 7 16:10:40 Setting cov_cutoff to 3.461. Aug 7 16:10:44 Setting cov_cutoff to 2.139. Looking for best cutoff score between 0.000 and 5.600 Max cutoff lies between 0.000 & 3.461 fc = 4615188 fd = 4615398 abs diff = 210 Aug 7 16:10:47 Setting cov_cutoff to 1.322. Max cutoff lies between 0.000 & 2.139 fc = 4615398 fd = 4615500 abs diff = 102 Aug 7 16:10:51 Setting cov_cutoff to 0.817. Max cutoff lies between 0.000 & 1.322 fc = 4615500 fd = 4615500 abs diff = 0 Aug 7 16:10:54 Setting cov_cutoff to 0.505. Max cutoff lies between 0.505 & 1.322 fc = 4615500 fd = 4615399 abs diff = 101 Aug 7 16:10:58 Setting cov_cutoff to 1.010. Optimum value of cutoff is 1.32 Took 5 iterations Aug 7 16:11:02 Final optimised assembly details: ******************************************************** Assembly id: 3 Assembly score: 4615405 Velveth timestamp: Aug 7 2018 16:10:13 Velvetg timestamp: Aug 7 2018 16:11:02 Velveth version: 1.2.10 Velvetg version: 1.2.10 Readfile(s): -shortPaired -separate -fastq.gz cabV2_read1.fq.gz cabV2_read2.fq.gz Velveth parameter string: auto_data_91 91 -shortPaired -separate -fastq.gz cabV2_read1.fq.gz cabV2_read2.fq.gz Velvetg parameter string: auto_data_91 -ins_length 300 -exp_cov 7 -cov_cutoff auto -min_contig_lgth 1000 -clean yes Assembly directory: /home/annotest/AssemblyWS/VelvetOptimiser/auto_data_91 Velvet hash value: 91 Roadmap file size: 40716059 Total number of contigs: 345 n50: 22892 length of longest contig: 112538 Total bases in contigs: 4615405 Number of contigs > 1k: 345 Total bases in contigs > 1k: 4615405 Paired Library insert stats: ********************************************************** Assembly output files are in the following directory: /home/annotest/AssemblyWS/VelvetOptimiser/auto_data_91
cd ..
/home/annotest/AssemblyWS
mkdir SPAdes
cd SPAdes
/home/annotest/AssemblyWS/SPAdes
%%bash
ln -s ../FASTQ/* .
ls -l
total 0 lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:14 cabV2_read1.fq.gz -> ../FASTQ/cabV2_read1.fq.gz lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:14 cabV2_read2.fq.gz -> ../FASTQ/cabV2_read2.fq.gz
/home/chumpol/AssemblyWS/SPAdes/Run_SPAdes.sh
cp /home/chumpol/AssemblyWS/SPAdes/Run_SPAdes.sh .
cat Run_SPAdes.sh
#!/bin/bash # $1 as number of threads # $2 as input file # $3 as output directory /share/apps/SPAdes-3.12.0-Linux/bin/spades.py -t $1 -1 ${2}_read1.fq.gz -2 ${2}_read2.fq.gz --only-assembler --cov-cutoff auto --careful -o $3
-t # : number of CPU threads to use
-1 file1 : paired read1 file
-2 file2 : paired read2 file
--only-assembler : runs only assembling (without read error correction)
--careful : tries to reduce number of mismatches and short indels
-o output : output directory
%%bash
./Run_SPAdes.sh 16 cabV2 SPAdes_Out
Command line: /share/apps/SPAdes-3.12.0-Linux/bin/spades.py -t 16 -1 /home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz -2 /home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz --only-assembler --cov-cutoff auto --careful -o /home/annotest/AssemblyWS/SPAdes/SPAdes_Out System information: SPAdes version: 3.12.0 Python version: 3.5.5 OS: Linux-3.10.0-514.26.2.el7.x86_64-x86_64-with-centos-7.4.1708-Core Output dir: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out Mode: ONLY assembling (without read error correction) Debug mode is turned OFF Dataset parameters: Multi-cell mode (you should set '--sc' flag if input data was obtained with MDA (single-cell) technology or --meta flag if processing metagenomic dataset) Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz'] right reads: ['/home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz'] interlaced reads: not specified single reads: not specified merged reads: not specified Assembly parameters: k: automatic selection based on read length Repeat resolution is enabled Mismatch careful mode is turned ON MismatchCorrector will be used Coverage cutoff is turned ON and threshold will be auto-detected Other parameters: Dir for temp files: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/tmp Threads: 16 Memory limit (in Gb): 250 ======= SPAdes pipeline started. Log can be found here: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/spades.log ===== Assembling started. == Running assembler: K21 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K21/configs/config.info 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K21/configs/careful_mode.info 0:00:00.001 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from N/A, git revision N/A 0:00:00.001 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.001 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/home/annotest/AssemblyWS/SPAdes/SPAdes_Out/dataset.info) with K=21 0:00:00.001 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 16 0:00:00.001 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 77) Converting reads to binary format for library #0 (takes a while) 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 78) Converting paired reads 0:00:00.311 80M / 80M INFO General (binary_converter.hpp : 93) 16384 reads processed 0:00:00.557 96M / 96M INFO General (binary_converter.hpp : 93) 32768 reads processed 0:00:01.046 124M / 124M INFO General (binary_converter.hpp : 93) 65536 reads processed 0:00:02.009 180M / 180M INFO General (binary_converter.hpp : 93) 131072 reads processed 0:00:03.491 296M / 296M INFO General (binary_converter.hpp : 93) 262144 reads processed 0:00:07.294 468M / 468M INFO General (binary_converter.hpp : 117) 462530 reads written 0:00:07.844 4M / 468M INFO General (read_converter.hpp : 87) Converting single reads 0:00:07.937 132M / 468M INFO General (binary_converter.hpp : 117) 0 reads written 0:00:07.937 4M / 468M INFO General (read_converter.hpp : 95) Converting merged reads 0:00:08.025 132M / 468M INFO General (binary_converter.hpp : 117) 0 reads written 0:00:08.027 4M / 468M INFO General (construction.cpp : 111) Max read length 151 0:00:08.027 4M / 468M INFO General (construction.cpp : 117) Average read length 151 0:00:08.027 4M / 468M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:08.027 4M / 468M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:08.027 4M / 468M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:08.027 4M / 468M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20825 Gb 0:00:08.027 4M / 468M INFO General (kmer_splitters.hpp : 97) Using cell size of 262144 0:00:12.163 8G / 8G INFO General (kmer_splitters.hpp : 289) Processed 1850120 reads 0:00:12.163 8G / 8G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:12.853 64M / 8G INFO General (kmer_splitters.hpp : 308) Used 1850120 reads 0:00:12.853 64M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:13.006 64M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 18798949 kmers in total. 0:00:13.007 64M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:13.225 64M / 8G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:13.225 64M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:13.225 64M / 8G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:13.225 64M / 8G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:13.225 64M / 8G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20703 Gb 0:00:13.225 64M / 8G INFO General (kmer_splitters.hpp : 97) Using cell size of 262144 0:00:16.612 8G / 8G INFO General (kmer_splitters.hpp : 380) Processed 18798949 kmers 0:00:16.612 8G / 8G INFO General (kmer_splitters.hpp : 385) Used 18798949 kmers. 0:00:17.289 64M / 8G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:17.435 64M / 8G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 18304331 kmers in total. 0:00:17.435 64M / 8G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:17.613 64M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:18.206 64M / 8G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:18.388 64M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 8496152 bytes occupied (3.71329 bits per kmer). 0:00:18.402 84M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:19.421 84M / 8G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:19.421 84M / 8G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:00:19.421 84M / 8G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:00:19.421 84M / 8G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:00:21.321 84M / 8G INFO Early tip clipping (early_simplification.hpp : 184) 3269566 22-mers were removed by early tip clipper 0:00:21.321 84M / 8G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:21.322 84M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:22.161 128M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1390562 sequences extracted 0:00:22.689 128M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:22.898 132M / 8G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:00:23.321 448M / 8G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:23.321 448M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:23.321 448M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:23.720 456M / 8G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 8725488 bytes occupied (3.71318 bits per kmer). 0:00:23.747 528M / 8G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:25.616 528M / 8G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:26.337 528M / 8G INFO General (construction.cpp : 464) Processed 2781021 edges 0:00:26.423 420M / 8G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:26.424 420M / 8G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 0:00:26.424 420M / 8G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 21 0:00:26.424 420M / 8G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 23. Coverage mad: 7.413 0:00:26.424 420M / 8G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:26.467 420M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:26.589 420M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:27.025 420M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:27.959 420M / 8G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:28.568 420M / 8G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 22.4523. Fitted coverage std. dev: 5.4301 0:00:28.568 420M / 8G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.872896 0:00:28.568 420M / 8G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 5 0:00:28.568 420M / 8G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 5 0:00:28.568 420M / 8G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 4603800 0:00:28.568 420M / 8G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 22.4523 0:00:28.568 420M / 8G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 5 0:00:28.569 420M / 8G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 1 0:00:28.569 420M / 8G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:28.569 420M / 8G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:28.569 420M / 8G INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:00:28.569 420M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:28.666 420M / 8G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:28.666 420M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:28.666 420M / 8G INFO General (simplification.cpp : 357) Graph simplification started 0:00:28.666 420M / 8G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:28.667 420M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:28.667 420M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:28.831 404M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 466 times 0:00:28.831 404M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:58.961 420M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 460110 times 0:00:58.961 420M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:58.987 428M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:58.987 428M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:58.987 428M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:59.041 392M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 175 times 0:00:59.041 392M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:59.041 392M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:00:59.041 392M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:59.529 340M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 16646 times 0:00:59.529 340M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:59.529 340M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:59.542 340M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 143 times 0:00:59.542 340M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.172 316M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3842 times 0:01:00.172 316M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.208 308M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1014 times 0:01:00.208 308M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:01:00.208 308M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.212 308M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.212 308M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.288 304M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 129 times 0:01:00.288 304M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.303 304M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 516 times 0:01:00.303 304M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:01:00.303 304M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.304 304M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:01:00.304 304M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.335 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 80 times 0:01:00.335 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.338 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 62 times 0:01:00.338 300M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:01:00.338 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.338 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.338 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.345 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 15 times 0:01:00.345 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.346 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 54 times 0:01:00.346 300M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:01:00.346 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.346 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.346 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.350 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 8 times 0:01:00.350 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.352 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 18 times 0:01:00.352 300M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:01:00.352 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.352 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.352 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.352 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 3 times 0:01:00.352 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.353 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 26 times 0:01:00.353 300M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:01:00.353 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.353 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.353 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 2 times 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 11 times 0:01:00.354 300M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:00.354 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.355 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 19 times 0:01:00.355 300M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:01:00.355 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.359 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.359 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.459 300M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 110 times 0:01:00.459 300M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:01:00.464 296M / 8G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:01:00.464 296M / 8G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:01:00.464 296M / 8G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:01:00.464 296M / 8G INFO General (graph_simplification.hpp : 453) Disconnection of relatively low covered edges disabled 0:01:00.464 296M / 8G INFO General (graph_simplification.hpp : 489) Complex tip clipping disabled 0:01:00.464 296M / 8G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:01:00.464 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.468 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.468 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.547 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 9 times 0:01:00.547 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.550 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.550 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.624 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:01:00.624 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:00.624 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:00.624 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:00.624 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:00.624 296M / 8G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:01:00.646 296M / 8G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:01:00.648 296M / 8G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 0 times 0:01:00.648 296M / 8G INFO General (simplification.cpp : 340) Removing all the edges having coverage 1 and less 0:01:00.651 296M / 8G INFO General (simplification.cpp : 470) Counting average coverage 0:01:00.659 296M / 8G INFO General (simplification.cpp : 476) Average coverage = 25.6143 0:01:00.659 296M / 8G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:01:00.659 296M / 8G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/assembly_graph_with_scaffolds.gfa 0:01:00.772 296M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/before_rr.fasta 0:01:00.902 296M / 8G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/assembly_graph.fastg 0:01:01.376 296M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/simplified_contigs.fasta 0:01:01.511 296M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/final_contigs.fasta 0:01:01.645 296M / 8G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:01:01.645 296M / 8G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/assembly_graph_with_scaffolds.gfa 0:01:01.762 296M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/before_rr.fasta 0:01:01.893 296M / 8G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/assembly_graph.fastg 0:01:02.369 296M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/simplified_contigs.fasta 0:01:02.508 296M / 8G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K21/final_contigs.fasta 0:01:02.655 296M / 8G INFO General (launch.hpp : 149) SPAdes finished 0:01:02.951 64M / 8G INFO General (main.cpp : 109) Assembling time: 0 hours 1 minutes 2 seconds Max read length detected as 151 Default k-mer sizes were set to [21, 33, 55, 77] because estimated read length (151) is equal to or greater than 150 == Running assembler: K33 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K33/configs/config.info 0:00:00.001 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K33/configs/careful_mode.info 0:00:00.001 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from N/A, git revision N/A 0:00:00.001 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.001 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/home/annotest/AssemblyWS/SPAdes/SPAdes_Out/dataset.info) with K=33 0:00:00.001 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 16 0:00:00.001 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.002 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.002 4M / 4M INFO General (construction.cpp : 117) Average read length 151 0:00:00.002 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.002 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:00.002 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.002 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20825 Gb 0:00:00.002 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:04.181 8G / 9G INFO General (kmer_splitters.hpp : 289) Processed 1850120 reads 0:00:04.181 8G / 9G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:06.101 64M / 9G INFO General (kmer_splitters.hpp : 308) Used 1850120 reads 0:00:06.101 64M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:06.407 64M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 23619460 kmers in total. 0:00:06.408 64M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:06.840 64M / 9G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:06.840 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:06.840 64M / 9G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:06.840 64M / 9G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:06.840 64M / 9G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20703 Gb 0:00:06.840 64M / 9G INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:10.574 8G / 9G INFO General (kmer_splitters.hpp : 380) Processed 23619460 kmers 0:00:10.574 8G / 9G INFO General (kmer_splitters.hpp : 385) Used 23619460 kmers. 0:00:11.367 64M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:11.580 64M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 23286214 kmers in total. 0:00:11.580 64M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:12.048 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:12.916 64M / 9G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:13.381 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 10806120 bytes occupied (3.71245 bits per kmer). 0:00:13.397 88M / 9G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:14.675 88M / 9G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:14.675 88M / 9G INFO General (stage.cpp : 101) PROCEDURE == Early tip clipping 0:00:14.676 88M / 9G INFO General (construction.cpp : 253) Early tip clipper length bound set as (RL - K) 0:00:14.676 88M / 9G INFO Early tip clipping (early_simplification.hpp : 181) Early tip clipping 0:00:16.978 88M / 9G INFO Early tip clipping (early_simplification.hpp : 184) 7137863 34-mers were removed by early tip clipper 0:00:16.979 88M / 9G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:16.980 88M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:18.027 124M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 962429 sequences extracted 0:00:18.593 124M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:18.893 124M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:00:19.292 348M / 9G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:19.293 348M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:19.293 348M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:19.799 372M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 10960640 bytes occupied (3.71241 bits per kmer). 0:00:19.842 464M / 9G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:21.816 464M / 9G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:22.648 464M / 9G INFO General (construction.cpp : 464) Processed 1924843 edges 0:00:22.774 312M / 9G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:22.774 312M / 9G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 0 0:00:22.774 312M / 9G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 18 0:00:22.774 312M / 9G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 19. Coverage mad: 7.413 0:00:22.774 312M / 9G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:22.799 312M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:22.869 312M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:23.131 312M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:23.776 312M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:24.508 308M / 9G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 18.8784. Fitted coverage std. dev: 5.07148 0:00:24.509 308M / 9G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.999913 0:00:24.509 308M / 9G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 4 0:00:24.509 308M / 9G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 4 0:00:24.509 308M / 9G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 4707199 0:00:24.509 308M / 9G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 18.8784 0:00:24.509 308M / 9G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 4 0:00:24.509 308M / 9G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:00:24.509 308M / 9G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:24.509 308M / 9G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:24.509 308M / 9G INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:00:24.509 308M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:24.586 308M / 9G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:24.586 308M / 9G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:24.586 308M / 9G INFO General (simplification.cpp : 357) Graph simplification started 0:00:24.586 308M / 9G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:24.586 308M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:24.586 308M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:24.729 296M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 915 times 0:00:24.729 296M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:45.998 268M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 322286 times 0:00:45.998 268M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.005 268M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 5 times 0:00:46.005 268M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:46.005 268M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.038 244M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 352 times 0:00:46.038 244M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3 times 0:00:46.039 244M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:46.039 244M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.173 224M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 4132 times 0:00:46.173 224M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:46.173 224M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.175 224M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 86 times 0:00:46.175 224M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.257 216M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 701 times 0:00:46.257 216M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.258 216M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 64 times 0:00:46.258 216M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:46.258 216M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.258 216M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.258 216M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.260 216M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 7 times 0:00:46.260 216M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.262 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 68 times 0:00:46.262 212M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:00:46.262 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.262 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.262 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 22 times 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 8 times 0:00:46.266 212M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3 times 0:00:46.266 212M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:46.266 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 9 times 0:00:46.267 212M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 5 times 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:46.267 212M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:46.267 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.268 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 9 times 0:00:46.268 212M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:00:46.268 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.270 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.270 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.313 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 25 times 0:00:46.313 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.318 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:46.318 212M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:00:46.318 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.318 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.318 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.318 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:46.318 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:46.319 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:46.319 212M / 9G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:46.319 212M / 9G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:46.319 212M / 9G INFO General (graph_simplification.hpp : 453) Disconnection of relatively low covered edges disabled 0:00:46.319 212M / 9G INFO General (graph_simplification.hpp : 489) Complex tip clipping disabled 0:00:46.319 212M / 9G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:46.319 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.321 212M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.321 212M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.353 204M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:00:46.353 204M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:46.355 204M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:46.355 204M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:46.386 204M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:46.386 204M / 9G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:46.396 204M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:00:46.398 204M / 9G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 11 times 0:00:46.398 204M / 9G INFO General (simplification.cpp : 470) Counting average coverage 0:00:46.402 204M / 9G INFO General (simplification.cpp : 476) Average coverage = 21.7425 0:00:46.402 204M / 9G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:46.402 204M / 9G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/assembly_graph_with_scaffolds.gfa 0:00:46.483 204M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/before_rr.fasta 0:00:46.579 204M / 9G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/assembly_graph.fastg 0:00:46.910 204M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/simplified_contigs.fasta 0:00:47.002 204M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/final_contigs.fasta 0:00:47.097 204M / 9G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:00:47.097 204M / 9G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/assembly_graph_with_scaffolds.gfa 0:00:47.175 204M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/before_rr.fasta 0:00:47.272 204M / 9G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/assembly_graph.fastg 0:00:47.608 204M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/simplified_contigs.fasta 0:00:47.704 204M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K33/final_contigs.fasta 0:00:47.807 204M / 9G INFO General (launch.hpp : 149) SPAdes finished 0:00:47.955 68M / 9G INFO General (main.cpp : 109) Assembling time: 0 hours 0 minutes 47 seconds == Running assembler: K55 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K55/configs/config.info 0:00:00.001 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K55/configs/careful_mode.info 0:00:00.001 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from N/A, git revision N/A 0:00:00.001 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.001 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/home/annotest/AssemblyWS/SPAdes/SPAdes_Out/dataset.info) with K=55 0:00:00.001 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 16 0:00:00.001 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO General (launch.hpp : 76) Will need read mapping, kmer mapper will be attached 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.001 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.001 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.001 4M / 4M INFO General (construction.cpp : 117) Average read length 151 0:00:00.001 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.002 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:00.002 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.002 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20825 Gb 0:00:00.002 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:04.658 8G / 9G INFO General (kmer_splitters.hpp : 289) Processed 1850120 reads 0:00:04.658 8G / 9G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:06.935 64M / 9G INFO General (kmer_splitters.hpp : 308) Used 1850120 reads 0:00:06.935 64M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:07.293 64M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 28314268 kmers in total. 0:00:07.293 64M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:07.877 64M / 9G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:07.877 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:07.877 64M / 9G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:07.877 64M / 9G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:07.877 64M / 9G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20703 Gb 0:00:07.877 64M / 9G INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:12.066 8G / 9G INFO General (kmer_splitters.hpp : 380) Processed 28314268 kmers 0:00:12.066 8G / 9G INFO General (kmer_splitters.hpp : 385) Used 28314268 kmers. 0:00:12.876 64M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:13.131 64M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 28202227 kmers in total. 0:00:13.131 64M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:13.652 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:14.854 64M / 9G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:15.411 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13085528 bytes occupied (3.71191 bits per kmer). 0:00:15.432 92M / 9G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:16.895 92M / 9G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:16.896 92M / 9G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:16.897 92M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:18.486 188M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1389218 sequences extracted 0:00:19.394 188M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:19.745 188M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:00:20.336 516M / 9G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:20.336 516M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:20.336 516M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:20.903 524M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13137352 bytes occupied (3.71187 bits per kmer). 0:00:20.970 636M / 9G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:22.758 636M / 9G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:24.249 636M / 9G INFO General (construction.cpp : 464) Processed 2778430 edges 0:00:24.444 472M / 9G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:24.444 472M / 9G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 0 0:00:24.444 472M / 9G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 13 0:00:24.444 472M / 9G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 13. Coverage mad: 5.9304 0:00:24.444 472M / 9G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:24.456 472M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:24.487 472M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:24.595 472M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:24.841 472M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:25.460 468M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 32 0:00:26.235 468M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 64 0:00:26.428 468M / 9G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 13.4147. Fitted coverage std. dev: 4.27326 0:00:26.429 468M / 9G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.999714 0:00:26.429 468M / 9G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 4 0:00:26.429 468M / 9G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 4 0:00:26.429 468M / 9G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 4788539 0:00:26.429 468M / 9G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 13.4147 0:00:26.429 468M / 9G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 4 0:00:26.429 468M / 9G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 0 0:00:26.429 468M / 9G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:26.429 468M / 9G INFO General (graph_pack.hpp : 101) Index refill 0:00:26.429 468M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:26.429 468M / 9G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:26.429 468M / 9G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:26.429 468M / 9G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.19881 Gb 0:00:26.429 468M / 9G INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:00:29.421 9G / 9G INFO General (edge_index_builders.hpp : 77) Processed 2778430 edges 0:00:29.421 9G / 9G INFO General (edge_index_builders.hpp : 82) Used 2778430 sequences. 0:00:30.192 468M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:30.427 468M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 28314268 kmers in total. 0:00:30.427 468M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:30.885 468M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:32.287 488M / 9G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:32.894 488M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13137352 bytes occupied (3.71187 bits per kmer). 0:00:33.194 1G / 9G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:00:34.116 1G / 9G INFO General (edge_index.hpp : 92) Index refilled 0:00:34.116 1G / 9G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:00:36.204 1G / 9G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:00:36.827 1G / 9G INFO General (gap_closer.cpp : 138) Used 462530 paired reads 0:00:36.827 1G / 9G INFO General (gap_closer.cpp : 140) Merging paired indices 0:00:37.296 1G / 9G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:00:40.791 1G / 9G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 42 gaps after checking 620 candidates 0:00:40.897 1G / 9G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:40.902 480M / 9G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:40.902 480M / 9G INFO General (graph_simplification.hpp : 662) Flanking coverage based disconnection disabled 0:00:40.902 480M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:41.018 480M / 9G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 1 times 0:00:41.018 480M / 9G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:41.018 480M / 9G INFO General (simplification.cpp : 357) Graph simplification started 0:00:41.019 480M / 9G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:41.019 480M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:41.019 480M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:47.765 492M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 538227 times 0:00:47.765 492M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.261 992M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 113653 times 0:01:18.262 992M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.267 1000M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 2 times 0:01:18.267 1000M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:01:18.267 1000M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.285 992M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 558 times 0:01:18.285 992M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 6 times 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 4 times 0:01:18.287 992M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:18.287 992M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.311 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 789 times 0:01:18.311 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:01:18.311 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.313 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 102 times 0:01:18.313 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 108 times 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 5 times 0:01:18.342 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 7 times 0:01:18.342 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.342 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 1 times 0:01:18.343 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 8 times 0:01:18.343 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:18.343 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.344 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 18 times 0:01:18.344 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:01:18.344 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.344 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.344 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.344 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:18.344 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.346 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 38 times 0:01:18.346 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:01:18.346 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.346 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.346 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.346 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:18.346 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.351 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 76 times 0:01:18.351 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:01:18.351 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.354 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.354 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.382 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 6 times 0:01:18.382 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.386 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:01:18.386 988M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:01:18.386 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:18.386 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:18.386 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:18.386 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:18.386 988M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:01:18.386 988M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:01:18.386 988M / 9G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:01:18.386 988M / 9G INFO General (graph_pack.hpp : 101) Index refill 0:01:18.386 988M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:01:18.386 988M / 9G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:01:18.386 988M / 9G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:01:18.386 988M / 9G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.18823 Gb 0:01:18.386 988M / 9G INFO General (kmer_splitters.hpp : 97) Using cell size of 131072 0:01:20.765 9G / 9G INFO General (edge_index_builders.hpp : 77) Processed 38109 edges 0:01:20.765 9G / 9G INFO General (edge_index_builders.hpp : 82) Used 38109 sequences. 0:01:21.696 988M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:01:21.819 988M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 5432667 kmers in total. 0:01:21.819 988M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:01:21.947 988M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:01:22.072 1000M / 9G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:01:22.177 1000M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 2527456 bytes occupied (3.72186 bits per kmer). 0:01:22.316 1G / 9G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:01:22.439 1G / 9G INFO General (edge_index.hpp : 92) Index refilled 0:01:22.439 1G / 9G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:01:22.466 1G / 9G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:01:24.538 1G / 9G INFO General (gap_closer.cpp : 138) Used 462530 paired reads 0:01:24.538 1G / 9G INFO General (gap_closer.cpp : 140) Merging paired indices 0:01:24.543 1G / 9G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:01:24.588 1G / 9G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 0 gaps after checking 24 candidates 0:01:24.591 1G / 9G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:01:24.591 1G / 9G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:01:24.591 1G / 9G INFO General (graph_simplification.hpp : 453) Disconnection of relatively low covered edges disabled 0:01:24.591 1G / 9G INFO General (graph_simplification.hpp : 489) Complex tip clipping disabled 0:01:24.591 1G / 9G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:01:24.591 1G / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:24.595 1G / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:24.595 1G / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:24.615 1G / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:01:24.615 1G / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:01:24.618 1G / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:01:24.618 1G / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:01:24.636 1G / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:01:24.636 1G / 9G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:01:24.651 1G / 9G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:01:25.067 1G / 9G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 6674 times 0:01:25.067 1G / 9G INFO General (simplification.cpp : 470) Counting average coverage 0:01:25.078 1G / 9G INFO General (simplification.cpp : 476) Average coverage = 14.9594 0:01:25.078 1G / 9G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:01:25.078 1G / 9G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/assembly_graph_with_scaffolds.gfa 0:01:25.153 1G / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/before_rr.fasta 0:01:25.235 1G / 9G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/assembly_graph.fastg 0:01:25.528 1G / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/simplified_contigs.fasta 0:01:25.610 1G / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/final_contigs.fasta 0:01:25.690 1G / 9G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:01:25.690 1G / 9G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/assembly_graph_with_scaffolds.gfa 0:01:25.766 1G / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/before_rr.fasta 0:01:25.848 1G / 9G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/assembly_graph.fastg 0:01:26.140 1G / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/simplified_contigs.fasta 0:01:26.225 1G / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K55/final_contigs.fasta 0:01:26.312 1G / 9G INFO General (launch.hpp : 149) SPAdes finished 0:01:31.344 72M / 9G INFO General (main.cpp : 109) Assembling time: 0 hours 1 minutes 31 seconds == Running assembler: K77 0:00:00.000 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K77/configs/config.info 0:00:00.001 4M / 4M INFO General (main.cpp : 74) Loaded config from /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/K77/configs/careful_mode.info 0:00:00.001 4M / 4M INFO General (memory_limit.cpp : 49) Memory limit set to 250 Gb 0:00:00.001 4M / 4M INFO General (main.cpp : 87) Starting SPAdes, built from N/A, git revision N/A 0:00:00.001 4M / 4M INFO General (main.cpp : 88) Maximum k-mer length: 128 0:00:00.001 4M / 4M INFO General (main.cpp : 89) Assembling dataset (/home/annotest/AssemblyWS/SPAdes/SPAdes_Out/dataset.info) with K=77 0:00:00.001 4M / 4M INFO General (main.cpp : 90) Maximum # of threads to use (adjusted due to OMP capabilities): 16 0:00:00.001 4M / 4M INFO General (launch.hpp : 51) SPAdes started 0:00:00.001 4M / 4M INFO General (launch.hpp : 58) Starting from stage: construction 0:00:00.001 4M / 4M INFO General (launch.hpp : 65) Two-step RR enabled: 0 0:00:00.001 4M / 4M INFO General (launch.hpp : 76) Will need read mapping, kmer mapper will be attached 0:00:00.001 4M / 4M INFO StageManager (stage.cpp : 132) STAGE == de Bruijn graph construction 0:00:00.002 4M / 4M INFO General (read_converter.hpp : 59) Binary reads detected 0:00:00.002 4M / 4M INFO General (construction.cpp : 111) Max read length 151 0:00:00.002 4M / 4M INFO General (construction.cpp : 117) Average read length 151 0:00:00.002 4M / 4M INFO General (stage.cpp : 101) PROCEDURE == k+1-mer counting 0:00:00.002 4M / 4M INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:00.002 4M / 4M INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:00.002 4M / 4M INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20825 Gb 0:00:00.002 4M / 4M INFO General (kmer_splitters.hpp : 97) Using cell size of 87381 0:00:05.302 8G / 9G INFO General (kmer_splitters.hpp : 289) Processed 1850120 reads 0:00:05.302 8G / 9G INFO General (kmer_splitters.hpp : 295) Adding contigs from previous K 0:00:07.111 64M / 9G INFO General (kmer_splitters.hpp : 308) Used 1850120 reads 0:00:07.111 64M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:08.494 64M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 28724894 kmers in total. 0:00:08.494 64M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:09.412 64M / 9G INFO General (stage.cpp : 101) PROCEDURE == Extension index construction 0:00:09.412 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:09.412 64M / 9G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:09.412 64M / 9G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:09.412 64M / 9G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20703 Gb 0:00:09.412 64M / 9G INFO General (kmer_splitters.hpp : 97) Using cell size of 87381 0:00:14.039 8G / 9G INFO General (kmer_splitters.hpp : 380) Processed 28724894 kmers 0:00:14.039 8G / 9G INFO General (kmer_splitters.hpp : 385) Used 28724894 kmers. 0:00:14.810 64M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:15.275 64M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 28787624 kmers in total. 0:00:15.275 64M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:16.031 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:17.075 64M / 9G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:18.029 64M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13356976 bytes occupied (3.71187 bits per kmer). 0:00:18.052 92M / 9G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 99) Building k-mer extensions from k+1-mers 0:00:19.604 92M / 9G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 103) Building k-mer extensions from k+1-mers finished. 0:00:19.605 92M / 9G INFO General (stage.cpp : 101) PROCEDURE == Condensing graph 0:00:19.607 92M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 355) Extracting unbranching paths 0:00:21.398 192M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 374) Extracting unbranching paths finished. 1160163 sequences extracted 0:00:22.400 192M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 310) Collecting perfect loops 0:00:22.759 192M / 9G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 343) Collecting perfect loops finished. 0 loops collected 0:00:23.348 464M / 9G INFO General (stage.cpp : 101) PROCEDURE == Filling coverage indices (PHM) 0:00:23.348 464M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:23.348 464M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:24.158 468M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13327808 bytes occupied (3.71185 bits per kmer). 0:00:24.220 580M / 9G INFO General (construction.cpp : 388) Collecting k-mer coverage information from reads, this takes a while. 0:00:25.615 580M / 9G INFO General (construction.cpp : 508) Filling coverage and flanking coverage from PHM 0:00:27.014 580M / 9G INFO General (construction.cpp : 464) Processed 2320325 edges 0:00:27.222 428M / 9G INFO StageManager (stage.cpp : 132) STAGE == EC Threshold Finding 0:00:27.222 428M / 9G INFO General (kmer_coverage_model.cpp : 181) Kmer coverage valley at: 2 0:00:27.222 428M / 9G INFO General (kmer_coverage_model.cpp : 201) K-mer histogram maximum: 8 0:00:27.222 428M / 9G INFO General (kmer_coverage_model.cpp : 237) Estimated median coverage: 9. Coverage mad: 4.4478 0:00:27.222 428M / 9G INFO General (kmer_coverage_model.cpp : 259) Fitting coverage model 0:00:27.231 428M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 2 0:00:27.252 428M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 4 0:00:27.323 428M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 8 0:00:27.472 428M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 16 0:00:27.697 424M / 9G INFO General (kmer_coverage_model.cpp : 295) ... iteration 32 0:00:27.802 420M / 9G INFO General (kmer_coverage_model.cpp : 309) Fitted mean coverage: 9.19109. Fitted coverage std. dev: 3.34463 0:00:27.802 420M / 9G INFO General (kmer_coverage_model.cpp : 334) Probability of erroneous kmer at valley: 0.354172 0:00:27.802 420M / 9G INFO General (kmer_coverage_model.cpp : 358) Preliminary threshold calculated as: 5 0:00:27.802 420M / 9G INFO General (kmer_coverage_model.cpp : 362) Threshold adjusted to: 5 0:00:27.802 420M / 9G INFO General (kmer_coverage_model.cpp : 375) Estimated genome size (ignoring repeats): 4449079 0:00:27.802 420M / 9G INFO General (genomic_info_filler.cpp : 112) Mean coverage was calculated as 9.19109 0:00:27.802 420M / 9G INFO General (genomic_info_filler.cpp : 127) EC coverage threshold value was calculated as 5 0:00:27.802 420M / 9G INFO General (genomic_info_filler.cpp : 128) Trusted kmer low bound: 1 0:00:27.802 420M / 9G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:27.802 420M / 9G INFO General (graph_pack.hpp : 101) Index refill 0:00:27.802 420M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:27.802 420M / 9G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:27.802 420M / 9G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:27.802 420M / 9G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.19979 Gb 0:00:27.802 420M / 9G INFO General (kmer_splitters.hpp : 97) Using cell size of 87381 0:00:31.220 9G / 9G INFO General (edge_index_builders.hpp : 77) Processed 2320325 edges 0:00:31.220 9G / 9G INFO General (edge_index_builders.hpp : 82) Used 2320325 sequences. 0:00:31.904 416M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:32.333 416M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 28724894 kmers in total. 0:00:32.333 416M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:33.009 416M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:34.197 440M / 9G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:35.166 440M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 13327808 bytes occupied (3.71185 bits per kmer). 0:00:35.435 1G / 9G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:00:36.291 1G / 9G INFO General (edge_index.hpp : 92) Index refilled 0:00:36.292 1G / 9G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:00:38.167 1G / 9G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:00:38.744 1G / 9G INFO General (gap_closer.cpp : 138) Used 462530 paired reads 0:00:38.744 1G / 9G INFO General (gap_closer.cpp : 140) Merging paired indices 0:00:39.262 1G / 9G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:00:42.495 1G / 9G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 82 gaps after checking 1106 candidates 0:00:42.691 1G / 9G INFO StageManager (stage.cpp : 132) STAGE == Raw Simplification 0:00:42.697 432M / 9G INFO General (simplification.cpp : 128) PROCEDURE == InitialCleaning 0:00:42.697 432M / 9G INFO General (simplification.cpp : 62) Most init cleaning disabled on main iteration 0:00:42.697 432M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Self conjugate edge remover 0:00:42.797 432M / 9G INFO Simplification (parallel_processing.hpp : 167) Self conjugate edge remover triggered 0 times 0:00:42.797 432M / 9G INFO StageManager (stage.cpp : 132) STAGE == Simplification 0:00:42.797 432M / 9G INFO General (simplification.cpp : 357) Graph simplification started 0:00:42.797 432M / 9G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:42.797 432M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 1 0:00:42.797 432M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:51.729 380M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 551441 times 0:00:51.729 380M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.255 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1919 times 0:00:52.255 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.276 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:52.276 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 2 0:00:52.276 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.277 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 12 times 0:00:52.277 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.277 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:52.277 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.280 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 94 times 0:00:52.280 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 3 0:00:52.280 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.282 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 60 times 0:00:52.282 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 9 times 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 3 times 0:00:52.286 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 4 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:00:52.286 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.287 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 18 times 0:00:52.287 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 5 0:00:52.287 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.287 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.287 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.288 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:00:52.288 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.291 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 85 times 0:00:52.291 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 6 0:00:52.291 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.291 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.292 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.292 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:52.292 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.305 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 257 times 0:00:52.305 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 7 0:00:52.305 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.305 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.305 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.305 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:52.305 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.329 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 443 times 0:00:52.329 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 8 0:00:52.329 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.329 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.329 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.329 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 1 times 0:00:52.329 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.363 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 607 times 0:00:52.363 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 9 0:00:52.363 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.363 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.363 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.363 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:52.363 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.398 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 572 times 0:00:52.398 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 10 0:00:52.398 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.398 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.398 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.398 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:52.398 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.438 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 503 times 0:00:52.438 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 11 0:00:52.438 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.455 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 1 times 0:00:52.455 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.481 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:52.481 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.496 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:52.496 392M / 9G INFO General (simplification.cpp : 362) PROCEDURE == Simplification cycle, iteration 12 0:00:52.496 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:52.496 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:52.496 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:52.496 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:52.496 392M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Low coverage edge remover 0:00:52.496 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Low coverage edge remover triggered 0 times 0:00:52.496 392M / 9G INFO StageManager (stage.cpp : 132) STAGE == Gap Closer 0:00:52.496 392M / 9G INFO General (graph_pack.hpp : 101) Index refill 0:00:52.497 392M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 301) Building kmer index 0:00:52.497 392M / 9G INFO General (kmer_index_builder.hpp : 117) Splitting kmer instances into 256 files using 16 threads. This might take a while. 0:00:52.497 392M / 9G INFO General (file_limit.hpp : 32) Open file limit set to 1024 0:00:52.497 392M / 9G INFO General (kmer_splitters.hpp : 89) Memory available for splitting buffers: 5.20036 Gb 0:00:52.497 392M / 9G INFO General (kmer_splitters.hpp : 97) Using cell size of 87381 0:00:55.146 9G / 9G INFO General (edge_index_builders.hpp : 77) Processed 142399 edges 0:00:55.146 9G / 9G INFO General (edge_index_builders.hpp : 82) Used 142399 sequences. 0:00:55.840 388M / 9G INFO General (kmer_index_builder.hpp : 120) Starting k-mer counting. 0:00:56.003 388M / 9G INFO General (kmer_index_builder.hpp : 127) K-mer counting done. There are 9706450 kmers in total. 0:00:56.003 388M / 9G INFO General (kmer_index_builder.hpp : 133) Merging temporary buckets. 0:00:56.238 388M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 314) Building perfect hash indices 0:00:56.487 392M / 9G INFO General (kmer_index_builder.hpp : 150) Merging final buckets. 0:00:56.792 392M / 9G INFO K-mer Index Building (kmer_index_builder.hpp : 336) Index built. Total 4508952 bytes occupied (3.71625 bits per kmer). 0:00:57.029 616M / 9G INFO General (edge_index_builders.hpp : 107) Collecting edge information from graph, this takes a while. 0:00:57.304 616M / 9G INFO General (edge_index.hpp : 92) Index refilled 0:00:57.305 616M / 9G INFO General (gap_closer.cpp : 159) Preparing shift maps 0:00:57.515 636M / 9G INFO General (gap_closer.cpp : 119) Processing paired reads (takes a while) 0:00:58.964 636M / 9G INFO General (gap_closer.cpp : 138) Used 462530 paired reads 0:00:58.964 636M / 9G INFO General (gap_closer.cpp : 140) Merging paired indices 0:00:59.042 616M / 9G INFO GapCloser (gap_closer.cpp : 346) Closing short gaps 0:00:59.203 616M / 9G INFO GapCloser (gap_closer.cpp : 380) Closing short gaps complete: filled 1 gaps after checking 181 candidates 0:00:59.242 616M / 9G INFO StageManager (stage.cpp : 132) STAGE == Simplification Cleanup 0:00:59.242 616M / 9G INFO General (simplification.cpp : 196) PROCEDURE == Post simplification 0:00:59.242 616M / 9G INFO General (graph_simplification.hpp : 453) Disconnection of relatively low covered edges disabled 0:00:59.242 616M / 9G INFO General (graph_simplification.hpp : 489) Complex tip clipping disabled 0:00:59.242 616M / 9G INFO General (graph_simplification.hpp : 634) Creating parallel br instance 0:00:59.242 616M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:59.273 616M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:59.273 616M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:59.297 616M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:59.297 616M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Tip clipper 0:00:59.314 616M / 9G INFO Simplification (parallel_processing.hpp : 167) Tip clipper triggered 0 times 0:00:59.314 616M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Bulge remover 0:00:59.335 616M / 9G INFO Simplification (parallel_processing.hpp : 167) Bulge remover triggered 0 times 0:00:59.335 616M / 9G INFO General (simplification.cpp : 330) Disrupting self-conjugate edges 0:00:59.432 616M / 9G INFO Simplification (parallel_processing.hpp : 165) Running Removing isolated edges 0:01:03.531 392M / 9G INFO Simplification (parallel_processing.hpp : 167) Removing isolated edges triggered 68071 times 0:01:03.531 392M / 9G INFO General (simplification.cpp : 340) Removing all the edges having coverage 1 and less 0:01:03.532 392M / 9G INFO General (simplification.cpp : 470) Counting average coverage 0:01:03.533 392M / 9G INFO General (simplification.cpp : 476) Average coverage = 9.393 0:01:03.533 392M / 9G INFO StageManager (stage.cpp : 132) STAGE == Mismatch Correction 0:01:03.533 392M / 9G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 311881 kmers to process 0:01:03.724 388M / 9G INFO General (graph_pack.hpp : 111) Normalizing done 0:01:06.678 400M / 9G INFO General (mismatch_shall_not_pass.hp: 189) Finished collecting potential mismatches positions 0:01:06.774 388M / 9G INFO General (mismatch_shall_not_pass.hp: 290) All edges processed 0:01:06.775 388M / 9G INFO General (mismatch_correction.cpp : 27) Corrected 0 nucleotides 0:01:06.776 388M / 9G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:01:06.776 388M / 9G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/assembly_graph_with_scaffolds.gfa 0:01:06.838 388M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/before_rr.fasta 0:01:06.900 388M / 9G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/assembly_graph.fastg 0:01:07.127 388M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/simplified_contigs.fasta 0:01:07.203 388M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/intermediate_contigs.fasta 0:01:07.279 388M / 9G INFO StageManager (stage.cpp : 132) STAGE == Paired Information Counting 0:01:07.292 388M / 9G INFO General (graph_pack.hpp : 109) Normalizing k-mer map. Total 311881 kmers to process 0:01:07.292 388M / 9G INFO General (graph_pack.hpp : 111) Normalizing done 0:01:07.293 388M / 9G INFO General (pair_info_count.cpp : 320) Min edge length for estimation: 6989 0:01:07.293 388M / 9G INFO General (pair_info_count.cpp : 331) Estimating insert size for library #0 0:01:07.293 388M / 9G INFO General (pair_info_count.cpp : 190) Estimating insert size (takes a while) 0:01:07.397 660M / 9G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:01:09.274 660M / 9G INFO General (sequence_mapper_notifier.h: 98) Total 462530 reads processed 0:01:10.663 660M / 9G INFO General (pair_info_count.cpp : 209) Edge pairs: 67108864 (rough upper limit) 0:01:10.663 660M / 9G INFO General (pair_info_count.cpp : 213) 189193 paired reads (40.9039% of all) aligned to long edges 0:01:10.665 388M / 9G INFO General (pair_info_count.cpp : 354) Insert size = 300.004, deviation = 29.9794, left quantile = 262, right quantile = 338, read length = 151 0:01:10.730 580M / 9G INFO General (pair_info_count.cpp : 371) Filtering data for library #0 0:01:10.730 580M / 9G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:01:12.298 580M / 9G INFO General (sequence_mapper_notifier.h: 98) Total 462530 reads processed 0:01:12.298 580M / 9G INFO General (pair_info_count.cpp : 383) Mapping library #0 0:01:12.298 580M / 9G INFO General (pair_info_count.cpp : 385) Mapping paired reads (takes a while) 0:01:12.298 580M / 9G INFO General (pair_info_count.cpp : 289) Left insert size quantile 262, right insert size quantile 338, filtering threshold 2, rounding threshold 0 0:01:12.310 592M / 9G INFO General (pair_info_count.cpp : 39) Selecting usual mapper 0:01:13.865 592M / 9G INFO General (sequence_mapper_notifier.h: 98) Total 462530 reads processed 0:01:13.877 388M / 9G INFO StageManager (stage.cpp : 132) STAGE == Distance Estimation 0:01:13.877 388M / 9G INFO General (distance_estimation.cpp : 173) Processing library #0 0:01:13.877 388M / 9G INFO General (distance_estimation.cpp : 149) Weight Filter Done 0:01:13.877 388M / 9G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator 0:01:13.910 388M / 9G INFO General (distance_estimation.cpp : 34) Filtering info 0:01:13.910 388M / 9G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 17495 0:01:13.921 392M / 9G INFO General (pair_info_filters.hpp : 263) Done filtering 0:01:13.921 388M / 9G INFO General (distance_estimation.cpp : 156) Refining clustered pair information 0:01:13.927 388M / 9G INFO General (distance_estimation.cpp : 158) The refining of clustered pair information has been finished 0:01:13.927 388M / 9G INFO General (distance_estimation.cpp : 160) Improving paired information 0:01:13.947 388M / 9G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 620; contradictional = 628 0:01:13.967 388M / 9G INFO PairInfoImprover (pair_info_improver.hpp : 103) Paired info stats: missing = 33; contradictional = 0 0:01:13.967 388M / 9G INFO General (distance_estimation.cpp : 103) Filling scaffolding index 0:01:13.967 388M / 9G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SMOOTHING distance estimator 0:01:13.971 388M / 9G INFO General (distance_estimation.cpp : 34) Filtering info 0:01:13.971 388M / 9G INFO General (pair_info_filters.hpp : 242) Start filtering; index size: 6265 0:01:13.974 388M / 9G INFO General (pair_info_filters.hpp : 263) Done filtering 0:01:13.974 388M / 9G INFO General (distance_estimation.cpp : 182) Clearing raw paired index 0:01:13.977 388M / 9G INFO StageManager (stage.cpp : 132) STAGE == Repeat Resolving 0:01:13.977 388M / 9G INFO General (repeat_resolving.cpp : 69) Using Path-Extend repeat resolving 0:01:13.977 388M / 9G INFO General (launcher.cpp : 477) ExSPAnder repeat resolving tool started 0:01:13.992 400M / 9G INFO General (launcher.cpp : 392) Creating main extenders, unique edge length = 2000 0:01:13.992 400M / 9G INFO General (extenders_logic.cpp : 275) Estimated coverage of library #0 is 9.393 0:01:13.993 400M / 9G INFO General (extenders_logic.cpp : 275) Estimated coverage of library #0 is 9.393 0:01:13.994 400M / 9G INFO General (extenders_logic.cpp : 472) Using 1 paired-end library 0:01:13.994 400M / 9G INFO General (extenders_logic.cpp : 473) Using 1 paired-end scaffolding library 0:01:13.994 400M / 9G INFO General (extenders_logic.cpp : 474) Using 0 single read libraries 0:01:13.994 400M / 9G INFO General (launcher.cpp : 420) Total number of extenders is 3 0:01:13.994 400M / 9G INFO General (path_extender.hpp : 885) Processed 0 paths from 3082 (0%) 0:01:14.011 400M / 9G INFO General (path_extender.hpp : 883) Processed 128 paths from 3082 (4%) 0:01:14.022 404M / 9G INFO General (path_extender.hpp : 883) Processed 256 paths from 3082 (8%) 0:01:14.027 404M / 9G INFO General (path_extender.hpp : 885) Processed 309 paths from 3082 (10%) 0:01:14.052 404M / 9G INFO General (path_extender.hpp : 883) Processed 512 paths from 3082 (16%) 0:01:14.066 404M / 9G INFO General (path_extender.hpp : 885) Processed 618 paths from 3082 (20%) 0:01:14.107 408M / 9G INFO General (path_extender.hpp : 885) Processed 927 paths from 3082 (30%) 0:01:14.114 408M / 9G INFO General (path_extender.hpp : 883) Processed 1024 paths from 3082 (33%) 0:01:14.153 412M / 9G INFO General (path_extender.hpp : 885) Processed 1236 paths from 3082 (40%) 0:01:14.229 416M / 9G INFO General (path_extender.hpp : 885) Processed 1545 paths from 3082 (50%) 0:01:14.299 416M / 9G INFO General (path_extender.hpp : 885) Processed 1854 paths from 3082 (60%) 0:01:14.343 420M / 9G INFO General (path_extender.hpp : 883) Processed 2048 paths from 3082 (66%) 0:01:14.365 420M / 9G INFO General (path_extender.hpp : 885) Processed 2163 paths from 3082 (70%) 0:01:14.432 424M / 9G INFO General (path_extender.hpp : 885) Processed 2472 paths from 3082 (80%) 0:01:14.508 428M / 9G INFO General (path_extender.hpp : 885) Processed 2781 paths from 3082 (90%) 0:01:14.532 428M / 9G INFO General (launcher.cpp : 234) Finalizing paths 0:01:14.532 428M / 9G INFO General (launcher.cpp : 236) Deduplicating paths 0:01:14.546 420M / 9G INFO General (launcher.cpp : 240) Paths deduplicated 0:01:14.546 420M / 9G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 0:01:14.546 420M / 9G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths 0:01:14.546 420M / 9G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 0:01:14.546 420M / 9G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 0:01:14.549 420M / 9G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps 0:01:14.551 420M / 9G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 0:01:14.554 420M / 9G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 0:01:14.557 420M / 9G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 0:01:14.561 420M / 9G INFO General (launcher.cpp : 257) Paths finalized 0:01:14.561 420M / 9G INFO General (launcher.cpp : 427) Closing gaps in paths 0:01:14.568 424M / 9G INFO General (launcher.cpp : 455) Gap closing completed 0:01:14.570 424M / 9G INFO General (launcher.cpp : 286) Traversing tandem repeats 0:01:14.594 424M / 9G INFO General (launcher.cpp : 296) Traversed 549 loops 0:01:14.594 424M / 9G INFO General (launcher.cpp : 234) Finalizing paths 0:01:14.594 424M / 9G INFO General (launcher.cpp : 236) Deduplicating paths 0:01:14.595 424M / 9G INFO General (launcher.cpp : 240) Paths deduplicated 0:01:14.595 424M / 9G INFO PEResolver (pe_resolver.hpp : 295) Removing overlaps 0:01:14.595 424M / 9G INFO PEResolver (pe_resolver.hpp : 298) Sorting paths 0:01:14.596 424M / 9G INFO PEResolver (pe_resolver.hpp : 305) Marking overlaps 0:01:14.596 424M / 9G INFO OverlapRemover (pe_resolver.hpp : 130) Marking start/end overlaps 0:01:14.597 424M / 9G INFO OverlapRemover (pe_resolver.hpp : 133) Marking remaining overlaps 0:01:14.598 424M / 9G INFO PEResolver (pe_resolver.hpp : 308) Splitting paths 0:01:14.599 424M / 9G INFO PEResolver (pe_resolver.hpp : 313) Deduplicating paths 0:01:14.599 424M / 9G INFO PEResolver (pe_resolver.hpp : 315) Overlaps removed 0:01:14.601 424M / 9G INFO General (launcher.cpp : 257) Paths finalized 0:01:14.604 424M / 9G INFO General (launcher.cpp : 529) ExSPAnder repeat resolving tool finished 0:01:14.625 400M / 9G INFO StageManager (stage.cpp : 132) STAGE == Contig Output 0:01:14.625 400M / 9G INFO General (contig_output_stage.cpp : 40) Writing GFA to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/assembly_graph_with_scaffolds.gfa 0:01:14.676 400M / 9G INFO General (contig_output.hpp : 22) Outputting contigs to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/before_rr.fasta 0:01:14.739 400M / 9G INFO General (contig_output_stage.cpp : 51) Outputting FastG graph to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/assembly_graph.fastg 0:01:14.954 404M / 9G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/final_contigs.paths 0:01:15.046 400M / 9G INFO General (contig_output_stage.cpp : 20) Outputting FastG paths to /home/annotest/AssemblyWS/SPAdes/SPAdes_Out//K77/scaffolds.paths 0:01:15.116 400M / 9G INFO General (launch.hpp : 149) SPAdes finished 0:01:15.296 68M / 9G INFO General (main.cpp : 109) Assembling time: 0 hours 1 minutes 15 seconds ===== Assembling finished. Used k-mer sizes: 21, 33, 55, 77 ===== Mismatch correction started. == Processing of scaffolds == Running contig polishing tool: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-corrector-core /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/mismatch_corrector/scaffolds/configs/corrector.info /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_scaffolds.fasta == Dataset description file was created: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/mismatch_corrector/scaffolds/configs/corrector.info /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/mismatch_corrector/scaffolds/configs/log.properties 0:00:00.000 4M / 4M INFO General (main.cpp : 58) Starting MismatchCorrector, built from N/A, git revision N/A 0:00:00.000 4M / 4M INFO General (main.cpp : 59) Maximum # of threads to use (adjusted due to OMP capabilities): 16 0:00:00.000 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 195) Splitting assembly... 0:00:00.000 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 196) Assembly file: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_scaffolds.fasta 0:00:00.174 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 203) Processing paired sublib of number 0 0:00:00.174 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 206) /home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz /home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz 0:00:00.174 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 140) Running bwa index ...: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa index -a is /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_scaffolds.fasta [bwa_index] Pack FASTA... 0.07 sec [bwa_index] Construct BWT for the packed sequence... [bwa_index] 1.31 seconds elapse. [bwa_index] Update BWT... 0.06 sec [bwa_index] Pack forward-only FASTA... 0.05 sec [bwa_index] Construct SA from BWT and Occ... 0.75 sec [main] Version: 0.7.12-r1039 [main] CMD: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa index -a is /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_scaffolds.fasta [main] Real time: 2.265 sec; CPU: 2.259 sec 0:00:02.442 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 149) Running bwa mem ...:/home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa mem -v 1 -t 16 /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_scaffolds.fasta /home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz /home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz > /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/tmp/corrector_o5hhdch0/lib0_VA0t3N/tmp.sam [main] Version: 0.7.12-r1039 [main] CMD: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa mem -v 1 -t 16 /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_scaffolds.fasta /home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz /home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz [main] Real time: 9.495 sec; CPU: 87.977 sec 0:00:11.999 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 209) Adding samfile /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/tmp/corrector_o5hhdch0/lib0_VA0t3N/tmp.sam 0:00:15.975 60M / 60M INFO DatasetProcessor (dataset_processor.cpp : 105) processed 1000000reads, flushing 0:00:16.183 20M / 60M INFO DatasetProcessor (dataset_processor.cpp : 235) Processing contigs 0:00:17.116 260M / 264M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_16_length_68666_cov_9.322297 processed with 27 changes in thread 11 0:00:17.186 280M / 284M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_15_length_75367_cov_9.330734 processed with 31 changes in thread 14 0:00:17.203 284M / 284M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_14_length_79082_cov_9.256731 processed with 30 changes in thread 10 0:00:17.266 288M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_12_length_80943_cov_9.156667 processed with 47 changes in thread 5 0:00:17.277 284M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_13_length_79621_cov_9.427487 processed with 22 changes in thread 3 0:00:17.321 280M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_11_length_86382_cov_9.255362 processed with 41 changes in thread 13 0:00:17.327 268M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_10_length_91841_cov_9.187971 processed with 40 changes in thread 0 0:00:17.444 276M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_9_length_93568_cov_9.157053 processed with 61 changes in thread 4 0:00:17.531 272M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_8_length_102123_cov_9.304206 processed with 45 changes in thread 15 0:00:17.564 264M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_5_length_105317_cov_9.323489 processed with 53 changes in thread 1 0:00:17.568 260M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_6_length_103454_cov_9.340192 processed with 46 changes in thread 7 0:00:17.638 248M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_7_length_103373_cov_9.283738 processed with 42 changes in thread 2 0:00:17.713 240M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_4_length_117049_cov_9.316383 processed with 56 changes in thread 9 0:00:17.840 232M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_3_length_127286_cov_9.299499 processed with 56 changes in thread 8 0:00:17.860 220M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_17_length_67221_cov_9.148710 processed with 42 changes in thread 11 0:00:17.918 216M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_19_length_59516_cov_9.118121 processed with 41 changes in thread 10 0:00:17.949 212M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_21_length_58500_cov_9.342707 processed with 40 changes in thread 3 0:00:17.953 208M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_20_length_59353_cov_9.146029 processed with 45 changes in thread 5 0:00:17.965 204M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_2_length_140662_cov_9.276381 processed with 60 changes in thread 12 0:00:17.965 204M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_22_length_56255_cov_9.120474 processed with 32 changes in thread 13 0:00:17.974 188M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_1_length_142002_cov_9.288807 processed with 83 changes in thread 6 0:00:17.976 188M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_23_length_54525_cov_9.206270 processed with 20 changes in thread 0 0:00:18.097 168M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_18_length_61016_cov_9.145982 processed with 36 changes in thread 14 0:00:18.153 164M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_25_length_53628_cov_9.122052 processed with 46 changes in thread 15 0:00:18.172 160M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_26_length_52671_cov_8.958684 processed with 29 changes in thread 1 0:00:18.195 156M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_24_length_54285_cov_9.341924 processed with 32 changes in thread 4 0:00:18.231 152M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_28_length_49923_cov_9.205292 processed with 32 changes in thread 2 0:00:18.272 152M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_27_length_51962_cov_9.223783 processed with 15 changes in thread 7 0:00:18.303 148M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_29_length_49269_cov_9.104692 processed with 32 changes in thread 9 0:00:18.412 144M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_32_length_44267_cov_9.305386 processed with 17 changes in thread 10 0:00:18.426 144M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_30_length_46027_cov_9.221349 processed with 19 changes in thread 8 0:00:18.444 140M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_34_length_42977_cov_9.193357 processed with 25 changes in thread 5 0:00:18.450 140M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_31_length_45461_cov_9.278821 processed with 20 changes in thread 11 0:00:18.452 136M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_38_length_40177_cov_9.005012 processed with 20 changes in thread 6 0:00:18.452 132M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_37_length_40871_cov_9.215571 processed with 14 changes in thread 0 0:00:18.459 128M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_33_length_42997_cov_9.426375 processed with 14 changes in thread 3 0:00:18.461 128M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_36_length_42333_cov_9.380561 processed with 13 changes in thread 12 0:00:18.462 120M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_35_length_42826_cov_9.105312 processed with 29 changes in thread 13 0:00:18.578 112M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_39_length_39763_cov_9.213929 processed with 21 changes in thread 14 0:00:18.611 112M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_42_length_36235_cov_9.288484 processed with 27 changes in thread 4 0:00:18.619 112M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_40_length_39706_cov_9.178480 processed with 28 changes in thread 15 0:00:18.631 108M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_41_length_39340_cov_9.266689 processed with 10 changes in thread 1 0:00:18.683 108M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_44_length_35354_cov_9.258951 processed with 15 changes in thread 7 0:00:18.687 108M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_43_length_35960_cov_9.286542 processed with 11 changes in thread 2 0:00:18.717 108M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_45_length_35098_cov_9.382456 processed with 7 changes in thread 9 0:00:18.762 112M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_54_length_27094_cov_9.077100 processed with 9 changes in thread 13 0:00:18.791 108M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_53_length_28791_cov_9.096399 processed with 12 changes in thread 12 0:00:18.797 104M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_52_length_29416_cov_8.992501 processed with 26 changes in thread 3 0:00:18.802 100M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_46_length_34659_cov_9.288271 processed with 17 changes in thread 10 0:00:18.821 96M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_50_length_31620_cov_9.175221 processed with 20 changes in thread 0 0:00:18.824 96M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_48_length_32089_cov_9.280301 processed with 21 changes in thread 5 0:00:18.869 92M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_55_length_26224_cov_9.265537 processed with 12 changes in thread 14 0:00:18.879 92M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_47_length_32658_cov_9.352353 processed with 15 changes in thread 8 0:00:18.887 88M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_49_length_31943_cov_9.358972 processed with 18 changes in thread 11 0:00:18.908 84M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_51_length_31299_cov_9.338928 processed with 17 changes in thread 6 0:00:18.913 84M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_56_length_26007_cov_9.247358 processed with 13 changes in thread 4 0:00:18.916 84M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_57_length_24953_cov_9.437128 processed with 17 changes in thread 15 0:00:18.917 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_58_length_24791_cov_9.431820 processed with 5 changes in thread 1 0:00:18.956 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_60_length_24062_cov_9.420930 processed with 7 changes in thread 2 0:00:18.974 84M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_59_length_24346_cov_9.340517 processed with 6 changes in thread 7 0:00:18.985 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_61_length_23950_cov_9.240355 processed with 14 changes in thread 9 0:00:19.034 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_62_length_23365_cov_9.311276 processed with 3 changes in thread 13 0:00:19.055 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_65_length_22151_cov_9.331974 processed with 4 changes in thread 10 0:00:19.060 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_63_length_23326_cov_9.087402 processed with 7 changes in thread 12 0:00:19.061 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_64_length_22851_cov_9.505225 processed with 13 changes in thread 3 0:00:19.063 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_67_length_21459_cov_9.305631 processed with 9 changes in thread 5 0:00:19.072 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_66_length_21630_cov_9.460168 processed with 7 changes in thread 0 0:00:19.114 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_70_length_20349_cov_9.175069 processed with 15 changes in thread 11 0:00:19.115 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_68_length_21372_cov_9.361446 processed with 4 changes in thread 14 0:00:19.128 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_69_length_20560_cov_8.885710 processed with 20 changes in thread 8 0:00:19.154 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_72_length_20049_cov_9.416383 processed with 1 changes in thread 4 0:00:19.193 80M / 288M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_71_length_20334_cov_9.237153 processed with 18 changes in thread 6 0:00:19.849 76M / 288M INFO DatasetProcessor (dataset_processor.cpp : 255) Gluing processed contigs 0:00:19.870 64M / 288M INFO General (main.cpp : 72) Correcting time: 0 hours 0 minutes 19 seconds == Processing of contigs == Running contig polishing tool: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-corrector-core /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/mismatch_corrector/contigs/configs/corrector.info /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_contigs.fasta == Dataset description file was created: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/mismatch_corrector/contigs/configs/corrector.info /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/mismatch_corrector/contigs/configs/log.properties 0:00:00.000 4M / 4M INFO General (main.cpp : 58) Starting MismatchCorrector, built from N/A, git revision N/A 0:00:00.001 4M / 4M INFO General (main.cpp : 59) Maximum # of threads to use (adjusted due to OMP capabilities): 16 0:00:00.001 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 195) Splitting assembly... 0:00:00.001 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 196) Assembly file: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_contigs.fasta 0:00:00.261 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 203) Processing paired sublib of number 0 0:00:00.261 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 206) /home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz /home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz 0:00:00.261 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 140) Running bwa index ...: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa index -a is /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_contigs.fasta [bwa_index] Pack FASTA... 0.07 sec [bwa_index] Construct BWT for the packed sequence... [bwa_index] 1.40 seconds elapse. [bwa_index] Update BWT... 0.06 sec [bwa_index] Pack forward-only FASTA... 0.05 sec [bwa_index] Construct SA from BWT and Occ... 0.76 sec [main] Version: 0.7.12-r1039 [main] CMD: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa index -a is /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_contigs.fasta [main] Real time: 2.360 sec; CPU: 2.351 sec 0:00:02.625 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 149) Running bwa mem ...:/home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa mem -v 1 -t 16 /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_contigs.fasta /home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz /home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz > /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/tmp/corrector_ts3eej1f/lib0_xpD8b2/tmp.sam [main] Version: 0.7.12-r1039 [main] CMD: /home/share/apps/SPAdes-3.12.0-Linux/bin/spades-bwa mem -v 1 -t 16 /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/misc/assembled_contigs.fasta /home/annotest/AssemblyWS/SPAdes/cabV2_read1.fq.gz /home/annotest/AssemblyWS/SPAdes/cabV2_read2.fq.gz [main] Real time: 9.463 sec; CPU: 90.052 sec 0:00:12.146 4M / 4M INFO DatasetProcessor (dataset_processor.cpp : 209) Adding samfile /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/tmp/corrector_ts3eej1f/lib0_xpD8b2/tmp.sam 0:00:15.640 56M / 56M INFO DatasetProcessor (dataset_processor.cpp : 105) processed 1000000reads, flushing 0:00:16.517 20M / 60M INFO DatasetProcessor (dataset_processor.cpp : 235) Processing contigs 0:00:16.820 88M / 88M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_16_length_20142_cov_9.388886 processed with 8 changes in thread 11 0:00:16.825 88M / 88M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_15_length_20345_cov_9.764210 processed with 0 changes in thread 15 0:00:16.832 88M / 88M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_11_length_22641_cov_9.907818 processed with 0 changes in thread 2 0:00:16.832 88M / 88M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_14_length_21372_cov_9.361446 processed with 4 changes in thread 3 0:00:16.841 88M / 88M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_13_length_21930_cov_9.955384 processed with 1 changes in thread 7 0:00:16.850 92M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_6_length_24310_cov_9.351917 processed with 6 changes in thread 1 0:00:16.857 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_8_length_24220_cov_9.404962 processed with 5 changes in thread 4 0:00:16.864 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_12_length_22151_cov_9.331974 processed with 3 changes in thread 14 0:00:16.869 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_9_length_23745_cov_9.673187 processed with 5 changes in thread 5 0:00:16.873 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_10_length_23680_cov_9.427319 processed with 6 changes in thread 8 0:00:16.874 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_2_length_28101_cov_9.624358 processed with 7 changes in thread 0 0:00:16.881 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_7_length_24297_cov_9.539595 processed with 6 changes in thread 13 0:00:16.892 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_5_length_26093_cov_9.203990 processed with 6 changes in thread 6 0:00:16.900 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_3_length_27449_cov_9.297348 processed with 4 changes in thread 9 0:00:16.910 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_4_length_27046_cov_9.518818 processed with 5 changes in thread 10 0:00:16.977 88M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_1_length_31311_cov_9.432349 processed with 0 changes in thread 12 0:00:17.085 84M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_17_length_20131_cov_9.570460 processed with 1 changes in thread 11 0:00:17.105 80M / 92M INFO DatasetProcessor (dataset_processor.cpp : 251) Contig NODE_18_length_20049_cov_9.416383 processed with 1 changes in thread 15 0:00:20.082 80M / 92M INFO DatasetProcessor (dataset_processor.cpp : 255) Gluing processed contigs 0:00:20.109 64M / 92M INFO General (main.cpp : 72) Correcting time: 0 hours 0 minutes 20 seconds ===== Mismatch correction finished. * Assembled contigs are in /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/contigs.fasta * Assembled scaffolds are in /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/scaffolds.fasta * Assembly graph is in /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/assembly_graph.fastg * Assembly graph in GFA format is in /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/assembly_graph_with_scaffolds.gfa * Paths in the assembly graph corresponding to the contigs are in /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/contigs.paths * Paths in the assembly graph corresponding to the scaffolds are in /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/scaffolds.paths ======= SPAdes pipeline finished. SPAdes log can be found here: /home/annotest/AssemblyWS/SPAdes/SPAdes_Out/spades.log Thank you for using SPAdes!
-Use 16 CPU threads
-Output is saved in SPAdes_Out directory
cd ..
/home/annotest/AssemblyWS
mkdir MaSuRCA
cd MaSuRCA
/home/annotest/AssemblyWS/MaSuRCA
%%bash
ln -s ../FASTQ/* .
ls -l
total 0 lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:28 cabV2_read1.fq.gz -> ../FASTQ/cabV2_read1.fq.gz lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:28 cabV2_read2.fq.gz -> ../FASTQ/cabV2_read2.fq.gz
%%bash
/share/apps/MaSuRCA-3.2.8/bin/masurca -G config.txt
nano config.txt
Change the contents as follow :
PE= pe 300 50 cabV2_read1.fq.gz cabV2_read2.fq.gz
#JUMP= sh 3600 200 /FULL_PATH/short_1.fastq /FULL_PATH/short_2.fastq
cat config.txt
# example configuration file # DATA is specified as type {PE,JUMP,OTHER,PACBIO} and 5 fields: # 1)two_letter_prefix 2)mean 3)stdev 4)fastq(.gz)_fwd_reads # 5)fastq(.gz)_rev_reads. The PE reads are always assumed to be # innies, i.e. --->.<---, and JUMP are assumed to be outties # <---.--->. If there are any jump libraries that are innies, such as # longjump, specify them as JUMP and specify NEGATIVE mean. Reverse reads # are optional for PE libraries and mandatory for JUMP libraries. Any # OTHER sequence data (454, Sanger, Ion torrent, etc) must be first # converted into Celera Assembler compatible .frg files (see # http://wgs-assembler.sourceforge.com) DATA #Illumina paired end reads supplied as <two-character prefix> <fragment mean> <fragment stdev> <forward_reads> <reverse_reads> #if single-end, do not specify <reverse_reads> #MUST HAVE Illumina paired end reads to use MaSuRCA PE= pe 300 50 cabV2_read1.fq.gz cabV2_read2.fq.gz #Illumina mate pair reads supplied as <two-character prefix> <fragment mean> <fragment stdev> <forward_reads> <reverse_reads> #JUMP= sh 3600 200 /FULL_PATH/short_1.fastq /FULL_PATH/short_2.fastq #pacbio OR nanopore reads must be in a single fasta or fastq file with absolute path, can be gzipped #if you have both types of reads supply them both as NANOPORE type #PACBIO=/FULL_PATH/pacbio.fa #NANOPORE=/FULL_PATH/nanopore.fa #Other reads (Sanger, 454, etc) one frg file, concatenate your frg files into one if you have many #OTHER=/FULL_PATH/file.frg END PARAMETERS #set this to 1 if your Illumina jumping library reads are shorter than 100bp EXTEND_JUMP_READS=0 #this is k-mer size for deBruijn graph values between 25 and 127 are supported, auto will compute the optimal size based on the read data and GC content GRAPH_KMER_SIZE = auto #set this to 1 for all Illumina-only assemblies #set this to 0 if you have more than 15x coverage by long reads (Pacbio or Nanopore) or any other long reads/mate pairs (Illumina MP, Sanger, 454, etc) USE_LINKING_MATES = 0 #specifies whether to run mega-reads correction on the grid USE_GRID=0 #specifies queue to use when running on the grid MANDATORY GRID_QUEUE=all.q #batch size in the amount of long read sequence for each batch on the grid GRID_BATCH_SIZE=300000000 #use at most this much coverage by the longest Pacbio or Nanopore reads LHE_COVERAGE=30 #set to 1 to only do one pass of mega-reads, for faster but worse quality assembly MEGA_READS_ONE_PASS=0 #this parameter is useful if you have too many Illumina jumping library mates. Typically set it to 60 for bacteria and 300 for the other organisms LIMIT_JUMP_COVERAGE = 300 #these are the additional parameters to Celera Assembler. do not worry about performance, number or processors or batch sizes -- these are computed automatically. #set cgwErrorRate=0.25 for bacteria and 0.1<=cgwErrorRate<=0.15 for other organisms. CA_PARAMETERS = cgwErrorRate=0.15 #minimum count k-mers used in error correction 1 means all k-mers are used. one can increase to 2 if Illumina coverage >100 KMER_COUNT_THRESHOLD = 1 #whether to attempt to close gaps in scaffolds with Illumina data CLOSE_GAPS=1 #auto-detected number of cpus to use NUM_THREADS = 16 #this is mandatory jellyfish hash size -- a safe value is estimated_genome_size*estimated_coverage JF_SIZE = 200000000 #set this to 1 to use SOAPdenovo contigging/scaffolding module. Assembly will be worse but will run faster. Useful for very large (>5Gbp) genomes from Illumina-only data SOAP_ASSEMBLY=0 END
%%bash
/share/apps/MaSuRCA-3.2.8/bin/masurca config.txt
Verifying PATHS... jellyfish OK runCA OK createSuperReadsForDirectory.perl OK creating script file for the actions...done. execute assemble.sh to run assembly
ls -l
total 20 -rwxr-xr-x 1 jupyterhub1 jupyterhub1 13467 Aug 7 16:31 assemble.sh* lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:28 cabV2_read1.fq.gz -> ../FASTQ/cabV2_read1.fq.gz lrwxrwxrwx 1 jupyterhub1 jupyterhub1 26 Aug 7 16:28 cabV2_read2.fq.gz -> ../FASTQ/cabV2_read2.fq.gz -rw-rw-r-- 1 jupyterhub1 jupyterhub1 3503 Aug 7 16:30 config.txt
%%bash
./assemble.sh
[Tue Aug 7 16:31:53 +07 2018] Processing pe library reads [Tue Aug 7 16:31:55 +07 2018] Average PE read length 151 [Tue Aug 7 16:31:56 +07 2018] Using kmer size of 99 for the graph [Tue Aug 7 16:31:56 +07 2018] MIN_Q_CHAR: 33 [Tue Aug 7 16:31:56 +07 2018] Creating mer database for Quorum [Tue Aug 7 16:32:00 +07 2018] Error correct PE. [Tue Aug 7 16:32:12 +07 2018] Estimating genome size. [Tue Aug 7 16:32:16 +07 2018] Estimated genome size: 4694327 [Tue Aug 7 16:32:16 +07 2018] Creating k-unitigs with k=99 [Tue Aug 7 16:32:27 +07 2018] Computing super reads from PE [Tue Aug 7 16:32:31 +07 2018] Celera Assembler [Tue Aug 7 16:32:32 +07 2018] ovlMerThreshold=75 [Tue Aug 7 16:33:08 +07 2018] Overlap/unitig success [Tue Aug 7 16:33:08 +07 2018] recomputing A-stat for super-reads [Tue Aug 7 16:33:34 +07 2018] recomputing A-stat for super-reads [Tue Aug 7 16:33:36 +07 2018] Unitig consensus success [Tue Aug 7 16:34:03 +07 2018] CA success [Tue Aug 7 16:34:03 +07 2018] No gap closing possible. [Tue Aug 7 16:34:08 +07 2018] Assembly complete, final scaffold sequences are in CA/final.genome.scf.fasta [Tue Aug 7 16:34:08 +07 2018] All done
=================================================================================================================
Compare the quality of the assemblers
Software is installed at /share/quast-5.0.0
cd ..
/home/annotest/AssemblyWS
mkdir QUAST
cd QUAST
/home/annotest/AssemblyWS/QUAST
%%bash
ln -s ../Velvet/Test_75/contigs.fa contigs_velvet_K75.fa
%%bash
ln -s ../VelvetOptimiser/auto_data_91/contigs.fa contigs_velvetOpt_K91.fa
%%bash
ln -s ../SPAdes/SPAdes_Out/contigs.fasta contigs_SPAdes.fa
%%bash
ln -s ../SPAdes/SPAdes_Out/scaffolds.fasta scaffolds_SPAdes.fa
%%bash
ln -s ../MaSuRCA/CA/final.genome.scf.fasta scaffolds_MaSuRCA.fa
%%bash
ln -s ../FASTA/cabV2.fa .
%%bash
/share/apps/quast-5.0.0/quast.py -r cabV2.fa -t 4 contigs_velvet_K75.fa contigs_velvetOpt_K91.fa contigs_SPAdes.fa scaffolds_SPAdes.fa scaffolds_MaSuRCA.fa -o QUAST_Report
/share/apps/quast-5.0.0/quast.py -r cabV2.fa -t 4 contigs_velvet_K75.fa contigs_velvetOpt_K91.fa contigs_SPAdes.fa scaffolds_SPAdes.fa scaffolds_MaSuRCA.fa -o QUAST_Report Version: 5.0.0 System information: OS: Linux-3.10.0-514.26.2.el7.x86_64-x86_64-with-centos-7.4.1708-Core (linux_64) Python version: 3.5.5 CPUs number: 144 Started: 2018-08-07 16:40:51 Logging to /home/annotest/AssemblyWS/QUAST/QUAST_Report/quast.log CWD: /home/annotest/AssemblyWS/QUAST Main parameters: MODE: default, threads: 4, minimum contig length: 500, minimum alignment length: 65, \ ambiguity: one, threshold for extensive misassembly size: 1000 Reference: /home/annotest/AssemblyWS/QUAST/cabV2.fa ==> cabV2 Contigs: Pre-processing... 1 contigs_velvet_K75.fa ==> contigs_velvet_K75 2 contigs_velvetOpt_K91.fa ==> contigs_velvetOpt_K91 3 contigs_SPAdes.fa ==> contigs_SPAdes 4 scaffolds_SPAdes.fa ==> scaffolds_SPAdes 5 scaffolds_MaSuRCA.fa ==> scaffolds_MaSuRCA 2018-08-07 16:40:56 Running Basic statistics processor... Reference genome: cabV2.fa, length = 4799920, num fragments = 1, GC % = 31.97 Contig files: 1 contigs_velvet_K75 2 contigs_velvetOpt_K91 3 contigs_SPAdes 4 scaffolds_SPAdes 5 scaffolds_MaSuRCA Calculating N50 and L50... 1 contigs_velvet_K75, N50 = 55329, L50 = 25, Total length = 4591890, GC % = 31.99, # N's per 100 kbp = 441.80 2 contigs_velvetOpt_K91, N50 = 22892, L50 = 57, Total length = 4615405, GC % = 31.99, # N's per 100 kbp = 1012.61 3 contigs_SPAdes, N50 = 8046, L50 = 171, Total length = 4589773, GC % = 31.98, # N's per 100 kbp = 0.00 4 scaffolds_SPAdes, N50 = 49269, L50 = 29, Total length = 4644726, GC % = 31.99, # N's per 100 kbp = 1160.89 5 scaffolds_MaSuRCA, N50 = 63511, L50 = 20, Total length = 4615776, GC % = 32.01, # N's per 100 kbp = 0.00 Drawing Nx plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/Nx_plot.pdf Drawing NGx plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/NGx_plot.pdf Drawing cumulative plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/cumulative_plot.pdf Drawing GC content plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/GC_content_plot.pdf Drawing contigs_velvet_K75 GC content plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/contigs_velvet_K75_GC_content_plot.pdf Drawing contigs_velvetOpt_K91 GC content plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/contigs_velvetOpt_K91_GC_content_plot.pdf Drawing contigs_SPAdes GC content plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/contigs_SPAdes_GC_content_plot.pdf Drawing scaffolds_SPAdes GC content plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/scaffolds_SPAdes_GC_content_plot.pdf Drawing scaffolds_MaSuRCA GC content plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/scaffolds_MaSuRCA_GC_content_plot.pdf Drawing Coverage histogram (bin size: 1x)... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/coverage_histogram.pdf Drawing contigs_velvet_K75 coverage histogram (bin size: 1x)... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/contigs_velvet_K75_coverage_histogram.pdf Drawing contigs_velvetOpt_K91 coverage histogram (bin size: 1x)... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/contigs_velvetOpt_K91_coverage_histogram.pdf Drawing contigs_SPAdes coverage histogram (bin size: 1x)... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/contigs_SPAdes_coverage_histogram.pdf Drawing scaffolds_SPAdes coverage histogram (bin size: 1x)... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/basic_stats/scaffolds_SPAdes_coverage_histogram.pdf Done. 2018-08-07 16:41:01 Running Contig analyzer... 1 contigs_velvet_K75 1 Logging to files /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/contigs_report_contigs_velvet_K75.stdout and contigs_report_contigs_velvet_K75.stderr... 1 Aligning contigs to the reference 2 contigs_velvetOpt_K91 2 Logging to files /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/contigs_report_contigs_velvetOpt_K91.stdout and contigs_report_contigs_velvetOpt_K91.stderr... 2 Aligning contigs to the reference 3 contigs_SPAdes 3 Logging to files /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/contigs_report_contigs_SPAdes.stdout and contigs_report_contigs_SPAdes.stderr... 3 Aligning contigs to the reference 4 scaffolds_SPAdes 4 Logging to files /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/contigs_report_scaffolds_SPAdes.stdout and contigs_report_scaffolds_SPAdes.stderr... 4 Aligning contigs to the reference 1 Analysis is finished. 5 scaffolds_MaSuRCA 5 Logging to files /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/contigs_report_scaffolds_MaSuRCA.stdout and contigs_report_scaffolds_MaSuRCA.stderr... 5 Aligning contigs to the reference 3 Analysis is finished. 2 Analysis is finished. 4 Analysis is finished. 5 Analysis is finished. Creating total report... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/misassemblies_report.txt, misassemblies_report.tsv, and misassemblies_report.tex Transposed version of total report... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/transposed_report_misassemblies.txt, transposed_report_misassemblies.tsv, and transposed_report_misassemblies.tex Creating total report... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/unaligned_report.txt, unaligned_report.tsv, and unaligned_report.tex Drawing misassemblies by types plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/misassemblies_plot.pdf Drawing misassemblies FRCurve plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/contigs_reports/misassemblies_frcurve_plot.pdf Done. 2018-08-07 16:41:08 Running NA-NGA calculation... 1 contigs_velvet_K75, Largest alignment = 171055, NA50 = 44603, NGA50 = 43734, LA50 = 27, LGA50 = 29 2 contigs_velvetOpt_K91, Largest alignment = 112338, NA50 = 20897, NGA50 = 19883, LA50 = 58, LGA50 = 63 3 contigs_SPAdes, Largest alignment = 31311, NA50 = 8044, NGA50 = 7841, LA50 = 171, LGA50 = 185 4 scaffolds_SPAdes, Largest alignment = 139088, NA50 = 44026, NGA50 = 42900, LA50 = 31, LGA50 = 33 5 scaffolds_MaSuRCA, Largest alignment = 219320, NA50 = 63511, NGA50 = 62173, LA50 = 20, LGA50 = 22 Drawing cumulative plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/aligned_stats/cumulative_plot.pdf Drawing NAx plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/aligned_stats/NAx_plot.pdf Drawing NGAx plot... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/aligned_stats/NGAx_plot.pdf Done. 2018-08-07 16:41:09 Running Genome analyzer... NOTICE: No file with genomic features were provided. Use the --features option if you want to specify it. NOTICE: No file with operons were provided. Use the -O option if you want to specify it. 1 contigs_velvet_K75 2 contigs_velvetOpt_K91 3 contigs_SPAdes 4 scaffolds_SPAdes 1 Analysis is finished. 5 scaffolds_MaSuRCA 2 Analysis is finished. 3 Analysis is finished. 4 Analysis is finished. 5 Analysis is finished. Drawing Genome fraction, % histogram... saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/genome_stats/genome_fraction_histogram.pdf Done. NOTICE: Genes are not predicted by default. Use --gene-finding or --glimmer option to enable it. 2018-08-07 16:41:13 Creating large visual summaries... This may take a while: press Ctrl-C to skip this step.. 1 of 2: Creating Icarus viewers... 2 of 2: Creating PDF with all tables and plots... Done 2018-08-07 16:41:18 RESULTS: Text versions of total report are saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/report.txt, report.tsv, and report.tex Text versions of transposed total report are saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/transposed_report.txt, transposed_report.tsv, and transposed_report.tex HTML version (interactive tables and plots) is saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/report.html PDF version (tables and plots) is saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/report.pdf Icarus (contig browser) is saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/icarus.html Log is saved to /home/annotest/AssemblyWS/QUAST/QUAST_Report/quast.log Finished: 2018-08-07 16:41:18 Elapsed time: 0:00:26.266695 NOTICEs: 3; WARNINGs: 0; non-fatal ERRORs: 0 Thank you for using QUAST!
The report is generated in QUAST_Report directory.
cd ~/public_html
cp -rp ../AssemblyWS/QUAST/QUAST_Report .
ls -l
total 16 -rwxr-xr-x 1 annotest annotest 151 Aug 1 02:48 index.html* drwxrwxr-x 11 annotest annotest 4096 Aug 1 03:10 JBrowse/ drwxrwxr-x 7 jupyterhub1 jupyterhub1 4096 Aug 7 16:41 QUAST_Report/ drwxrwxr-x 3 annotest annotest 4096 Aug 6 21:33 Tomato/
http://breedserve.cab.kps.ku.ac.th/~annotest/QUAST_Report/report.html
change ~annotest to your username
from IPython.display import HTML
HTML(filename="/home/annotest/public_html/QUAST_Report/report.html")
QUASTQuality Assessment Tool for Genome Assemblies by CAB |
Loading...
Aligned to
""
Combined reference
Estimated reference size:
bp
|
bp
|
references
|
fragments
|
% G+C
|
chromosomes
reads
|
% mapped
|
% properly paired
genes
|
operons
Contigs are ordered from largest (contig #1) to smallest. FRCurve: Y is the total number of aligned bases divided by the reference length, in the contigs having the total number of at most X. Contigs are broken into nonoverlapping 100 bp windows. Plot shows number of windows for each GC percentage. Plot shows number of contigs with GC percentage in a certain range. |