== Warning == No assembly mode was specified! If you intend to assemble high-coverage multi-cell/isolate data, use '--isolate' option. == Warning == Isolate mode already implies --only-assembler, so this option has no effect. ======= SPAdes pipeline continued. Log can be found here: /home/denis/data/Pot_Spades_assembly/Spades_PA_out/spades.log Restored from Command line: /home/denis/miniconda3/envs/S_pades/bin/spades.py --only-assembler -1 /home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R1_001.fastq.gz -2 /home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R2_001.fastq.gz --nanopore /home/denis/data/Pot_Spades_assembly/ONT_total.fq --isolate -t 15 -m 200 -o /home/denis/data/Pot_Spades_assembly/Spades_PA_out Command line: /home/denis/miniconda3/envs/S_pades/bin/spades.py --only-assembler -1 /home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R1_001.fastq.gz -2 /home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R2_001.fastq.gz --nanopore /home/denis/data/Pot_Spades_assembly/ONT_total.fq --isolate -t 15 -m 200 -o /home/denis/data/Pot_Spades_assembly/Spades_PA_out -t 35 -m 450 Restart-from=last with updated parameters: -t 35 -m 450 System information: SPAdes version: 4.0.0 Python version: 3.13.1 OS: Linux-5.15.0-125-generic-x86_64-with-glibc2.35 Output dir: /home/denis/data/Pot_Spades_assembly/Spades_PA_out Mode: ONLY assembling (without read error correction) Debug mode is turned OFF Dataset parameters: Isolate mode Reads: Library number: 1, library type: paired-end orientation: fr left reads: ['/home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R1_001.fastq.gz'] right reads: ['/home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R2_001.fastq.gz'] interlaced reads: not specified single reads: not specified merged reads: not specified Library number: 2, library type: nanopore left reads: not specified right reads: not specified interlaced reads: not specified single reads: ['/home/denis/data/Pot_Spades_assembly/ONT_total.fq'] merged reads: not specified Assembly parameters: k: automatic selection based on read length Repeat resolution is enabled Mismatch careful mode is turned OFF MismatchCorrector will be SKIPPED Coverage cutoff is turned OFF Assembly graph output will use GFA v1.2 format Other parameters: Dir for temp files: /home/denis/data/Pot_Spades_assembly/Spades_PA_out/tmp Threads: 35 Memory limit (in Gb): 450 /home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R1_001.fastq.gz: max reads length: 150 /home/denis/data/Pot/R_GCTCATGA-TCTTACGC_L004_R2_001.fastq.gz: max reads length: 150 Reads length: 150 Default k-mer sizes were set to [21, 33, 55, 77] because estimated read length (150) is equal to or greater than 150 ===== Before start started. ===== Assembling started. ===== Skipping K21 (already processed) ===== Skipping K33 (already processed) ===== Skipping K55 (already processed) ===== K77 started. == Running: /home/denis/miniconda3/envs/S_pades/bin/spades-core /home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/config.info /home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/isolate_mode.info 0:00:00.000 1M / 18M INFO General (main.cpp : 94) Loaded config from "/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/config.info" 0:00:00.002 1M / 18M INFO General (main.cpp : 94) Loaded config from "/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/isolate_mode.info" 0:00:00.002 1M / 18M INFO General (memory_limit.cpp : 55) Memory limit set to 450 Gb 0:00:00.003 1M / 18M INFO General (main.cpp : 102) Starting SPAdes, built from N/A, git revision N/A 0:00:00.003 1M / 18M INFO General (main.cpp : 103) Maximum k-mer length: 128 0:00:00.003 1M / 18M INFO General (main.cpp : 104) Assembling dataset ("/home/denis/data/Pot_Spades_assembly/Spades_PA_out/dataset.info") with K=77 0:00:00.003 1M / 18M INFO General (main.cpp : 105) Maximum # of threads to use (adjusted due to OMP capabilities): 35 0:00:00.003 1M / 18M INFO General (pipeline.cpp : 212) SPAdes started 0:00:00.003 1M / 18M INFO General (pipeline.cpp : 225) Starting from stage: last 0:00:00.003 1M / 18M INFO General (pipeline.cpp : 234) Two-step repeat resolution disabled 0:00:00.007 1M / 18M INFO GraphCore (graph_core.hpp : 689) Graph created, vertex min_id: 3, edge min_id: 3 0:00:00.007 1M / 18M INFO GraphCore (graph_core.hpp : 690) Vertex size: 48, edge size: 40 0:00:00.012 1M / 18M INFO General (edge_index.hpp : 132) Size of edge index entries: 12/8 0:00:00.022 1M / 18M INFO General (pipeline.cpp : 245) Will need read mapping, kmer mapper will be attached 0:00:00.024 1M / 18M WARN StageManager (stage.cpp : 162) No saved checkpoint 0:00:00.024 1M / 18M INFO StageManager (stage.cpp : 189) STAGE == Binary Read Conversion (id: read_conversion) 0:00:00.032 1M / 18M INFO General (read_converter.cpp : 78) Converting reads to binary format for library #0 (takes a while) 0:00:00.032 1M / 18M INFO General (read_converter.cpp : 99) Converting paired reads 0:00:00.502 82M / 122M INFO General (binary_converter.cpp : 127) 16384 reads processed 0:00:00.514 82M / 123M INFO General (binary_converter.cpp : 127) 32768 reads processed 0:00:00.536 82M / 124M INFO General (binary_converter.cpp : 127) 65536 reads processed 0:00:06.794 82M / 180M INFO General (binary_converter.cpp : 127) 131072 reads processed 0:00:28.344 51M / 210M INFO General (binary_converter.cpp : 127) 262144 reads processed 0:00:58.988 0M / 287M INFO General (binary_converter.cpp : 127) 524288 reads processed 0:02:06.242 0M / 364M INFO General (binary_converter.cpp : 127) 1048576 reads processed 0:04:23.045 0M / 548M INFO General (binary_converter.cpp : 127) 2097152 reads processed 0:08:29.156 0M / 764M INFO General (binary_converter.cpp : 127) 4194304 reads processed 0:17:02.805 0M / 892M INFO General (binary_converter.cpp : 127) 8388608 reads processed 0:34:38.681 0M / 1160M INFO General (binary_converter.cpp : 127) 16777216 reads processed 1:08:41.395 0M / 1241M INFO General (binary_converter.cpp : 127) 33554432 reads processed 2:18:34.140 0M / 1399M INFO General (binary_converter.cpp : 127) 67108864 reads processed 4:39:28.755 0M / 1481M INFO General (binary_converter.cpp : 127) 134217728 reads processed 9:11:08.391 0M / 1645M INFO General (binary_converter.cpp : 127) 268435456 reads processed 11:14:28.153 0M / 1661M INFO General (binary_converter.cpp : 143) 329565923 reads written 11:14:28.163 0M / 1661M INFO General (read_converter.cpp : 113) Converting single reads 11:14:28.188 0M / 1661M INFO General (binary_converter.cpp : 143) 0 reads written 11:14:28.189 0M / 1661M INFO General (read_converter.cpp : 119) Converting merged reads 11:14:28.222 0M / 1661M INFO General (binary_converter.cpp : 143) 0 reads written 11:14:28.260 0M / 1661M INFO General (read_converter.cpp : 78) Converting reads to binary format for library #1 (takes a while) 11:14:28.261 0M / 1661M INFO General (read_converter.cpp : 99) Converting paired reads 11:14:28.273 0M / 1661M INFO General (binary_converter.cpp : 143) 0 reads written 11:14:28.276 0M / 1661M INFO General (read_converter.cpp : 113) Converting single reads 11:14:39.438 0M / 2008M INFO General (binary_converter.cpp : 127) 16384 reads processed 11:14:39.500 0M / 2008M INFO General (binary_converter.cpp : 127) 32768 reads processed 11:14:39.622 0M / 2008M INFO General (binary_converter.cpp : 127) 65536 reads processed 11:15:10.847 0M / 2618M INFO General (binary_converter.cpp : 127) 131072 reads processed 11:19:10.286 0M / 3867M INFO General (binary_converter.cpp : 127) 262144 reads processed 11:24:59.243 0M / 5462M INFO General (binary_converter.cpp : 127) 524288 reads processed 11:35:28.795 0M / 6697M INFO General (binary_converter.cpp : 143) 894399 reads written 11:35:28.813 0M / 6697M INFO General (read_converter.cpp : 119) Converting merged reads 11:35:28.823 0M / 6697M INFO General (binary_converter.cpp : 143) 0 reads written 11:35:28.967 1M / 6697M INFO StageManager (stage.cpp : 189) STAGE == de Bruijn graph construction (id: construction) 11:35:29.098 1M / 6697M INFO General (construction.cpp : 115) Contigs from previous K will be used: /home/denis/data/Pot_Spades_assembly/Spades_PA_out/K55/simplified_contigs 11:35:32.480 2M / 6697M INFO General (construction.cpp : 150) Max read length 150 11:35:32.480 2M / 6697M INFO General (construction.cpp : 156) Average read length 149.874 11:35:32.481 2M / 6697M INFO General (stage.cpp : 121) PROCEDURE == k+1-mer counting (id: construction:kpomer_counting) 11:35:32.481 2M / 6697M INFO General (kmer_index_builder.hpp : 258) Splitting kmer instances into 350 files using 35 threads. This might take a while. 11:35:32.487 2M / 6697M INFO General (file_limit.hpp : 43) Open file limit set to 1024 11:35:32.487 2M / 6697M INFO General (kmer_splitter.hpp : 94) Memory available for splitting buffers: 4.2857 Gb 11:35:32.487 2M / 6697M INFO General (kmer_splitter.hpp : 102) Using cell size of 63913 11:38:17.107 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 19862539 reads 11:41:05.669 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 39706873 reads 11:43:59.355 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 59515314 reads 11:46:57.629 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 79328755 reads 11:49:46.010 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 99162559 reads 11:52:35.348 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 118967156 reads 11:55:23.518 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 138734041 reads 11:58:09.031 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 158571410 reads 12:00:54.037 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 178456976 reads 12:03:39.322 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 198284369 reads 12:06:26.651 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 218160020 reads 12:09:05.051 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 237939153 reads 12:11:40.740 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 257906485 reads 12:14:23.577 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 277738863 reads 12:52:07.220 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 555767204 reads 14:04:19.699 20G / 20G INFO General (kmer_splitters.hpp : 128) Processed 1091760182 reads 14:37:54.270 3M / 19G INFO General (kmer_splitters.hpp : 134) Used 1341686472 reads 14:37:54.735 3M / 19G INFO General (kmer_index_builder.hpp : 264) Starting k-mer counting. 15:14:32.501 3M / 59G INFO General (kmer_index_builder.hpp : 275) K-mer counting done. There are 6100882538 kmers in total. 15:14:32.522 2M / 59G INFO General (stage.cpp : 121) PROCEDURE == Extension index construction (id: construction:extension_index_construction) 15:14:35.038 3M / 59G INFO K-mer Index Building (kmer_index_builder.hpp : 453) Building kmer index 15:14:35.039 3M / 59G INFO General (kmer_index_builder.hpp : 258) Splitting kmer instances into 350 files using 35 threads. This might take a while. 15:14:35.042 3M / 59G INFO General (file_limit.hpp : 43) Open file limit set to 1024 15:14:35.042 3M / 59G INFO General (kmer_splitter.hpp : 94) Memory available for splitting buffers: 4.28569 Gb 15:14:35.042 3M / 59G INFO General (kmer_splitter.hpp : 102) Using cell size of 63913 15:14:56.201 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 4909729 kmers 15:15:10.871 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 10049632 kmers 15:15:28.856 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 15656617 kmers 15:15:43.975 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 21250739 kmers 15:16:01.824 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 27295117 kmers 15:16:22.315 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 33114539 kmers 15:16:39.614 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 38908387 kmers 15:16:57.368 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 45177831 kmers 15:17:11.448 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 51410224 kmers 15:17:29.052 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 57938378 kmers 15:17:48.310 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 63948966 kmers 15:18:05.813 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 69960335 kmers 15:18:23.814 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 75963737 kmers 15:18:39.495 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 81906514 kmers 15:18:58.889 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 88596488 kmers 15:19:15.353 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 95443664 kmers 15:19:33.865 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 102169071 kmers 15:21:12.069 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 140701109 kmers 15:26:49.167 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 272400689 kmers 15:37:08.421 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 541835784 kmers 15:57:43.914 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 1077036780 kmers 16:36:50.787 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 2150275242 kmers 17:54:54.350 20G / 59G INFO General (kmer_splitters.hpp : 197) Processed 4298174333 kmers 19:01:39.796 20G / 59G INFO General (kmer_splitters.hpp : 202) Used 6101061563 kmers. 19:01:39.827 4M / 59G INFO General (kmer_index_builder.hpp : 264) Starting k-mer counting. 19:20:36.873 4M / 59G INFO General (kmer_index_builder.hpp : 275) K-mer counting done. There are 6108474838 kmers in total. 19:20:36.887 4M / 59G INFO K-mer Index Building (kmer_index_builder.hpp : 410) Building perfect hash indices 19:47:19.768 4475M / 59G INFO K-mer Index Building (kmer_index_builder.hpp : 446) Index built. Total 6108474838 kmers, 4412188000 bytes occupied (5.77845 bits per kmer). 19:47:19.813 4475M / 59G INFO General (kmer_index_builder.hpp : 168) Merging final buckets. mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (6115295232 bytes, address: 0x7f268fa9a000, alignment: 67108864, commit: 1) 20:59:21.426 11G / 59G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 101) Building k-mer extensions from k+1-mers 21:06:06.162 11G / 59G INFO DeBruijnExtensionIndexBu (kmer_extension_index_build: 106) Building k-mer extensions from k+1-mers finished. 21:06:07.601 11G / 59G INFO General (stage.cpp : 121) PROCEDURE == Condensing graph (id: construction:graph_condensing) 21:06:09.939 11G / 59G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 381) Extracting unbranching paths mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (4076863488 bytes, address: 0x7f1e76e10000, alignment: 67108864, commit: 1) 21:18:20.451 24G / 59G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 400) Extracting unbranching paths finished. 254437487 sequences extracted mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (4076863488 bytes, address: 0x7f1d81000000, alignment: 67108864, commit: 1) 21:22:05.175 24G / 59G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 336) Collecting perfect loops 21:29:19.362 24G / 59G INFO UnbranchingPathExtractor (debruijn_graph_constructor: 369) Collecting perfect loops finished. 44 loops collected mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (8149532672 bytes, address: 0x7f24a6400000, alignment: 67108864, commit: 1) mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (4076863488 bytes, address: 0x7f2841eff000, alignment: 67108864, commit: 1) 21:29:55.942 24G / 59G INFO DeBruijnGraphConstructor (debruijn_graph_constructor: 586) Sorting edges... 21:30:06.804 24G / 59G INFO DeBruijnGraphConstructor (debruijn_graph_constructor: 588) Edges sorted 21:30:06.805 24G / 59G INFO General (debruijn_graph_constructor: 516) Total 508875062 edges to create mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (20464009216 bytes, address: 0x7f21c8400000, alignment: 67108864, commit: 1) 21:30:06.832 43G / 59G INFO General (debruijn_graph_constructor: 519) Collecting link records mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (8149532672 bytes, address: 0x7f1fe2400000, alignment: 67108864, commit: 1) 21:34:16.046 50G / 59G INFO General (debruijn_graph_constructor: 521) Ordering link records 21:34:24.705 50G / 62G INFO General (debruijn_graph_constructor: 524) Sorting done mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (1077936128 bytes, address: 0x7f27ffc00000, alignment: 67108864, commit: 1) mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (2151677952 bytes, address: 0x7f1f5fc00000, alignment: 67108864, commit: 1) 21:34:28.804 52G / 62G INFO General (debruijn_graph_constructor: 537) Sorting LinkRecords... 21:34:37.786 52G / 62G INFO General (debruijn_graph_constructor: 540) LinkRecords sorted 21:34:37.791 52G / 62G INFO General (debruijn_graph_constructor: 542) Total 262029831 vertices to create mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (25287458816 bytes, address: 0x7f1978c00000, alignment: 67108864, commit: 1) 21:34:37.818 76G / 76G INFO General (debruijn_graph_constructor: 545) Connecting the graph 21:39:33.910 63G / 80G INFO General (stage.cpp : 121) PROCEDURE == Filling coverage indices (PHM) (id: construction:coverage_filling_phm) 21:39:33.917 63G / 80G INFO K-mer Index Building (kmer_index_builder.hpp : 410) Building perfect hash indices 22:05:52.644 67G / 80G INFO K-mer Index Building (kmer_index_builder.hpp : 446) Index built. Total 6100882538 kmers, 4406706360 bytes occupied (5.77845 bits per kmer). mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (24410849280 bytes, address: 0x7f13c9000000, alignment: 67108864, commit: 1) 22:06:28.100 90G / 93G INFO General (coverage_hash_map_builder.: 49) Collecting k-mer coverage information from reads, this takes a while. 22:31:34.166 90G / 93G INFO General (construction.cpp : 427) Filling coverage and flanking coverage from PHM 22:32:10.694 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 35000000 edges 22:32:44.905 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 70000000 edges 22:33:19.457 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 105000000 edges 22:33:54.752 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 140000000 edges 22:34:30.804 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 175000000 edges 22:35:07.192 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 210000000 edges 22:35:45.546 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 245000000 edges 22:36:15.295 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 274572084 edges 22:36:30.347 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 297144587 edges 22:36:43.967 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 318225277 edges 22:36:57.719 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 338635516 edges 22:37:12.013 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 358359764 edges 22:37:26.043 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 377166708 edges 22:37:40.348 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 395235768 edges 22:37:53.654 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 412489229 edges 22:38:08.095 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 429181767 edges 22:38:23.903 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 445106747 edges 22:38:38.021 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 459970116 edges 22:38:52.409 90G / 93G INFO General (coverage_filling.hpp : 83) Processed 473689886 edges 22:40:28.911 53G / 93G INFO StageManager (stage.cpp : 189) STAGE == EC Threshold Finding (id: ec_threshold_finder) 22:40:29.631 53G / 93G INFO General (kmer_coverage_model.cpp : 182) Kmer coverage valley at: 7 22:40:29.655 53G / 93G INFO General (kmer_coverage_model.cpp : 202) K-mer histogram maximum: 23 22:40:29.656 53G / 93G INFO General (kmer_coverage_model.cpp : 238) Estimated median coverage: 25. Coverage mad: 10.3782 22:40:29.671 53G / 93G INFO General (kmer_coverage_model.cpp : 260) Fitting coverage model 22:40:29.766 53G / 93G INFO General (kmer_coverage_model.cpp : 296) ... iteration 2 22:40:29.903 53G / 93G INFO General (kmer_coverage_model.cpp : 296) ... iteration 4 22:40:30.422 53G / 93G INFO General (kmer_coverage_model.cpp : 296) ... iteration 8 22:40:31.597 53G / 93G INFO General (kmer_coverage_model.cpp : 296) ... iteration 16 22:40:33.651 53G / 93G INFO General (kmer_coverage_model.cpp : 296) ... iteration 32 22:40:35.274 53G / 93G INFO General (kmer_coverage_model.cpp : 310) Fitted mean coverage: 31.6129. Fitted coverage std. dev: 14.5431 22:40:35.276 53G / 93G INFO General (kmer_coverage_model.cpp : 335) Probability of erroneous kmer at valley: 0.351945 22:40:35.276 53G / 93G INFO General (kmer_coverage_model.cpp : 359) Preliminary threshold calculated as: 12 22:40:35.276 53G / 93G INFO General (kmer_coverage_model.cpp : 363) Threshold adjusted to: 12 22:40:35.277 53G / 93G INFO General (kmer_coverage_model.cpp : 376) Estimated genome size (ignoring repeats): 862208641 22:40:35.286 53G / 93G INFO General (genomic_info_filler.cpp : 56) Mean coverage was calculated as 31.6129 22:40:35.287 53G / 93G INFO General (genomic_info_filler.cpp : 71) EC coverage threshold value was calculated as 12 22:40:35.287 53G / 93G INFO General (genomic_info_filler.cpp : 72) Trusted kmer low bound: 0 22:40:35.287 53G / 93G INFO StageManager (stage.cpp : 189) STAGE == Gap Closer (id: early_gapcloser) 22:40:35.299 53G / 93G INFO General (edge_index.hpp : 132) Size of edge index entries: 12/8 22:41:16.564 57G / 93G INFO General (gap_closer.cpp : 102) Total edges in tip neighborhood: 151080799 out of 508874070, length: 6410663018 mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (2424307712 bytes, address: 0x7f28a46ff000, alignment: 67108864, commit: 1) mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (2063597568 bytes, address: 0x7f2829000000, alignment: 67108864, commit: 1) 22:41:39.508 59G / 93G INFO General (edge_index.hpp : 196) Using small index (max_id = 511419440) 22:41:54.937 59G / 93G INFO K-mer Index Building (kmer_index_builder.hpp : 410) Building perfect hash indices mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (2319450112 bytes, address: 0x7f28aaaff000, alignment: 67108864, commit: 1) 22:46:14.432 62G / 93G INFO K-mer Index Building (kmer_index_builder.hpp : 446) Index built. Total 4816666717 kmers, 3478907672 bytes occupied (5.77812 bits per kmer). mimalloc: warning: unable to allocate aligned OS memory directly, fall back to over-allocation (38541459456 bytes, address: 0x7f107ec00000, alignment: 67108864, commit: 1) 22:46:50.121 98G / 106G INFO General (edge_index_builders.hpp : 266) Collecting edge information from graph, this takes a while. 22:49:27.486 96G / 106G INFO General (sequence_mapper_notifier.h: 64) Starting sequence mapping 22:50:10.006 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 200000 reads 22:50:10.381 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 400000 reads 22:50:10.531 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 600000 reads 22:50:11.154 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 800000 reads 22:50:11.323 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 1000000 reads 22:50:11.705 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 1200000 reads 22:50:11.912 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 2200000 reads 22:50:17.901 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 4200000 reads 22:50:55.773 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 8400000 reads 22:51:42.828 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 16800000 reads 22:53:46.320 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 33600000 reads 22:57:23.302 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 67200000 reads mimalloc: warning: thread 0x7f2953fc0640: unable to allocate aligned OS memory directly, fall back to over-allocation (1145044992 bytes, address: 0x7f28f0aff000, alignment: 67108864, commit: 1) 23:05:09.528 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 134400000 reads mimalloc: warning: thread 0x7f294afae640: unable to allocate aligned OS memory directly, fall back to over-allocation (2285895680 bytes, address: 0x7f2867c00000, alignment: 67108864, commit: 1) 23:20:27.442 96G / 106G INFO General (sequence_mapper_notifier.h: 85) Processed 268600000 reads 23:28:43.048 100G / 106G INFO General (sequence_mapper_notifier.h: 103) Total 329565923 reads processed 23:31:04.278 64G / 108G INFO General (gap_closer.cpp : 491) Initializing gap closer 23:31:04.363 64G / 108G INFO GapCloser (gap_closer.cpp : 406) Collecting gap candidates 23:31:26.371 64G / 108G INFO GapCloser (gap_closer.cpp : 410) Total 2796497 tips collected, total 3212893 connection candidates 23:31:39.755 64G / 108G INFO GapCloser (gap_closer.cpp : 431) Closing short gaps complete: filled 33767 gaps after checking 3175287 candidates 23:31:46.934 64G / 108G INFO General (gap_closer.cpp : 495) Gap closer done 23:32:02.369 53G / 108G INFO StageManager (stage.cpp : 189) STAGE == Raw Simplification (id: raw_simplification) 23:32:02.524 53G / 108G INFO General (simplification.cpp : 129) PROCEDURE == Initial cleaning 23:32:02.526 53G / 108G INFO General (simplification.cpp : 63) Most init cleaning disabled on main iteration 23:32:02.526 53G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Self conjugate edge remover 23:32:06.959 53G / 108G INFO Simplification (parallel_processing.hpp : 171) Self conjugate edge remover triggered 61 times 23:32:06.967 53G / 108G INFO StageManager (stage.cpp : 189) STAGE == Simplification (id: simplification) 23:32:06.967 53G / 108G INFO General (simplification.cpp : 397) Graph simplification started 23:32:06.968 53G / 108G INFO General (graph_simplification.hpp : 646) Creating parallel br instance 23:32:06.968 53G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 1 23:32:06.968 53G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 23:49:49.071 48G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 102700406 times 23:49:49.486 48G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:05:58.559 66G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 1524319 times 24:05:58.909 66G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:07:31.548 66G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 4821493 times 24:07:31.893 66G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 2 24:07:31.944 66G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:08:03.937 66G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 1271419 times 24:08:04.246 66G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:17:33.941 73G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 625617 times 24:17:34.149 73G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:18:03.542 73G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 1485948 times 24:18:03.870 73G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 3 24:18:03.980 73G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:18:12.731 73G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 168113 times 24:18:12.869 73G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:21:42.802 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 219225 times 24:21:42.974 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:21:49.769 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 384281 times 24:21:49.964 76G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 4 24:21:50.081 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:21:53.114 75G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 27596 times 24:21:53.243 75G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:22:49.445 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 56942 times 24:22:49.587 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:22:52.284 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 157704 times 24:22:52.426 76G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 5 24:22:52.522 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:22:53.715 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 8980 times 24:22:53.838 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:23:18.937 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 22999 times 24:23:19.072 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:23:20.787 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 91479 times 24:23:20.930 76G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 6 24:23:21.055 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:23:21.879 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 4294 times 24:23:22.001 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:23:37.354 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 13253 times 24:23:37.492 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:23:38.645 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 54274 times 24:23:38.786 77G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 7 24:23:38.902 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:23:39.370 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 2140 times 24:23:39.496 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:23:49.496 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 7707 times 24:23:49.624 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:23:50.589 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 43219 times 24:23:50.726 77G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 8 24:23:50.843 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:23:51.179 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 1414 times 24:23:51.300 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:23:59.619 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 5803 times 24:23:59.738 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:24:00.514 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 38440 times 24:24:00.648 77G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 9 24:24:00.765 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:24:01.169 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 1006 times 24:24:01.295 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:24:08.423 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 5079 times 24:24:08.549 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:24:09.305 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 38683 times 24:24:09.418 77G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 10 24:24:09.507 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:24:09.795 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 793 times 24:24:09.924 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:24:16.730 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 4698 times 24:24:16.863 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:24:17.913 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 44878 times 24:24:18.052 77G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 11 24:24:18.182 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:24:21.558 77G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 8451 times 24:24:21.684 77G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:26:18.277 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 82234 times 24:26:18.450 78G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:26:21.572 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 33 times 24:26:21.699 78G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 12 24:26:21.831 78G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:26:23.282 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 20 times 24:26:23.412 78G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:26:23.937 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 3 times 24:26:24.074 78G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:26:24.203 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 0 times 24:26:24.328 78G / 108G INFO General (simplification.cpp : 402) PROCEDURE == Simplification cycle, iteration 13 24:26:24.453 78G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 24:26:24.673 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 0 times 24:26:24.811 78G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 24:26:24.947 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 0 times 24:26:25.084 78G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Low coverage edge remover 24:26:25.221 78G / 108G INFO Simplification (parallel_processing.hpp : 171) Low coverage edge remover triggered 0 times 24:26:28.488 75G / 108G INFO StageManager (stage.cpp : 189) STAGE == Gap Closer (id: late_gapcloser) 24:26:28.627 75G / 108G INFO General (edge_index.hpp : 132) Size of edge index entries: 12/8 24:26:37.660 76G / 108G INFO General (gap_closer.cpp : 102) Total edges in tip neighborhood: 41715360 out of 62003402, length: 3113283421 24:26:41.552 77G / 108G INFO General (edge_index.hpp : 196) Using small index (max_id = 511419440) 24:26:45.920 77G / 108G INFO K-mer Index Building (kmer_index_builder.hpp : 410) Building perfect hash indices 24:27:57.394 78G / 108G INFO K-mer Index Building (kmer_index_builder.hpp : 446) Index built. Total 1562357367 kmers, 1128470546 bytes occupied (5.7783 bits per kmer). 24:28:02.642 89G / 108G INFO General (edge_index_builders.hpp : 266) Collecting edge information from graph, this takes a while. 24:28:46.660 89G / 108G INFO General (sequence_mapper_notifier.h: 64) Starting sequence mapping 24:30:01.614 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 200000 reads 24:30:01.682 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 400000 reads 24:30:06.966 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 600000 reads 24:30:06.967 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 800000 reads 24:30:06.967 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 1000000 reads 24:30:06.967 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 1200000 reads 24:30:06.967 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 2200000 reads 24:30:17.476 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 4200000 reads 24:31:22.466 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 8400000 reads 24:32:39.209 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 16800000 reads 24:36:22.261 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 33600000 reads 24:42:39.030 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 67200000 reads 24:56:07.632 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 134400000 reads 25:23:17.965 89G / 108G INFO General (sequence_mapper_notifier.h: 85) Processed 268600000 reads 25:37:53.656 90G / 108G INFO General (sequence_mapper_notifier.h: 103) Total 329565923 reads processed 25:38:06.826 77G / 108G INFO General (gap_closer.cpp : 491) Initializing gap closer 25:38:07.028 77G / 108G INFO GapCloser (gap_closer.cpp : 406) Collecting gap candidates 25:38:12.513 77G / 108G INFO GapCloser (gap_closer.cpp : 410) Total 291397 tips collected, total 401104 connection candidates 25:38:14.200 77G / 108G INFO GapCloser (gap_closer.cpp : 431) Closing short gaps complete: filled 330 gaps after checking 400441 candidates 25:38:17.196 77G / 108G INFO General (gap_closer.cpp : 495) Gap closer done 25:38:18.901 75G / 108G INFO StageManager (stage.cpp : 189) STAGE == Simplification Cleanup (id: simplification_cleanup) 25:38:19.025 75G / 108G INFO General (simplification.cpp : 189) PROCEDURE == Post simplification 25:38:19.127 75G / 108G INFO General (graph_simplification.hpp : 455) Disconnection of relatively low covered edges disabled 25:38:19.234 75G / 108G INFO General (graph_simplification.hpp : 494) Complex tip clipping disabled 25:38:19.348 75G / 108G INFO General (graph_simplification.hpp : 646) Creating parallel br instance 25:38:19.468 75G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 25:38:22.505 75G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 1 times 25:38:22.631 75G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 25:38:44.343 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 3267 times 25:38:44.463 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 25:38:47.468 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 1 times 25:38:47.602 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 25:39:05.777 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 166 times 25:39:05.920 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Tip clipper 25:39:06.059 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Tip clipper triggered 0 times 25:39:06.197 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Bulge remover 25:39:06.336 76G / 108G INFO Simplification (parallel_processing.hpp : 171) Bulge remover triggered 0 times 25:39:06.475 76G / 108G INFO General (simplification.cpp : 348) Disrupting self-conjugate edges 25:39:38.031 76G / 108G INFO Simplification (parallel_processing.hpp : 168) Running Removing isolated edges 25:40:13.022 75G / 108G INFO Simplification (parallel_processing.hpp : 171) Removing isolated edges triggered 20662779 times 25:40:15.237 74G / 108G INFO General (simplification.cpp : 508) After simplification: 25:40:15.361 74G / 108G INFO General (simplification.cpp : 509) Average coverage = 51.9709 25:40:17.240 74G / 108G INFO General (simplification.cpp : 510) Total length = 815362298 25:40:20.176 74G / 108G INFO General (simplification.cpp : 511) Median edge length: 180 25:40:20.305 74G / 108G INFO General (simplification.cpp : 512) Edges: 20657618 25:40:20.423 74G / 108G INFO General (simplification.cpp : 513) Vertices: 13912518 25:40:20.551 74G / 108G INFO StageManager (stage.cpp : 189) STAGE == Mismatch Correction (id: mismatch_correction) 25:40:20.689 74G / 108G INFO General (graph_pack_helpers.cpp : 44) Index refill 25:40:20.825 74G / 108G INFO General (edge_index.hpp : 175) Using small index (max_id = 511419440) 25:40:24.684 74G / 108G INFO K-mer Index Building (kmer_index_builder.hpp : 410) Building perfect hash indices 25:41:19.838 75G / 108G INFO K-mer Index Building (kmer_index_builder.hpp : 446) Index built. Total 815338040 kmers, 588933036 bytes occupied (5.77854 bits per kmer). 25:41:22.866 81G / 108G INFO General (edge_index_builders.hpp : 253) Collecting edge information from graph, this takes a while. 25:41:46.674 81G / 108G INFO General (graph_pack_helpers.cpp : 54) Normalizing k-mer map. Total 445893749 kmers to process 25:44:36.365 81G / 109G INFO General (graph_pack_helpers.cpp : 56) Normalizing done 25:44:36.489 81G / 109G INFO General (mismatch_correction.cpp : 392) Collect potential mismatches 25:46:50.503 83G / 109G INFO General (mismatch_correction.cpp : 193) Total 8016673 edges (out of 20657618) with 89170067 potential mismatch positions (11.1231 positions per edge) 25:46:50.958 82G / 109G INFO General (mismatch_correction.cpp : 394) Potential mismatches collected 25:46:55.283 82G / 109G INFO General (sequence_mapper_notifier.h: 64) Starting sequence mapping 25:47:05.762 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 200000 reads 25:47:05.788 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 400000 reads 25:47:05.829 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 600000 reads 25:47:05.874 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 800000 reads 25:47:06.015 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 1000000 reads 25:47:06.037 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 1200000 reads 25:47:06.183 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 2200000 reads 25:47:07.159 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 4200000 reads 25:47:16.217 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 8400000 reads 25:47:27.109 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 16800000 reads 25:47:55.386 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 33600000 reads 25:48:47.858 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 67200000 reads 25:50:36.816 82G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 134400000 reads 25:54:44.249 83G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 268600000 reads 26:06:32.196 83G / 109G INFO General (sequence_mapper_notifier.h: 85) Processed 537000000 reads 26:37:11.701 84G / 119G INFO General (sequence_mapper_notifier.h: 85) Processed 1073800000 reads 26:55:27.363 113G / 122G INFO General (sequence_mapper_notifier.h: 103) Total 1318263692 reads processed 26:55:46.139 85G / 122G INFO General (mismatch_correction.cpp : 387) All edges processed 26:55:48.517 81G / 122G INFO General (mismatch_correction.cpp : 442) Corrected 2927 nucleotides 26:55:49.173 81G / 122G INFO StageManager (stage.cpp : 189) STAGE == Contig Output (id: contig_output) 26:55:49.364 81G / 122G INFO General (contig_output.hpp : 20) Outputting contigs to "/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/before_rr.fasta" 35:09:12.173 81G / 122G INFO General (contig_output_stage.cpp : 155) Writing GFA graph to "/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/assembly_graph_after_simplification.gfa" 35:49:07.631 81G / 122G INFO StageManager (stage.cpp : 189) STAGE == Hybrid Aligning (id: hybrid_aligning) 35:49:07.826 81G / 122G INFO HybridAligning (hybrid_aligning.cpp : 346) Hybrid library detected: #1 35:49:08.021 81G / 122G INFO General (hybrid_aligning.cpp : 299) Aligning long reads with bwa-mem based aligner 35:49:08.201 81G / 122G INFO BWAIndex (bwa_index.cpp : 52) Setting BWA alignment mode to 'pacbio' 35:49:38.035 85G / 122G INFO General (bwa_index.cpp : 153) Using BWA RopeBWT algorithm 36:48:18.192 84G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 0 of 50000 reads. 36:51:00.579 84G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 35250 of them longer than 500; among long reads aligned: 26347; paths of more than one edge received: 2589 36:51:00.918 84G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 50000 reads 36:51:09.259 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 1 of 50000 reads. 36:56:41.915 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 42816 of them longer than 500; among long reads aligned: 41430; paths of more than one edge received: 12260 36:56:42.428 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 100000 reads 36:56:52.377 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 2 of 50000 reads. 37:04:52.199 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 44004 of them longer than 500; among long reads aligned: 42805; paths of more than one edge received: 13666 37:04:52.686 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 150000 reads 37:05:00.725 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 3 of 50000 reads. 37:11:13.768 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 44911 of them longer than 500; among long reads aligned: 43672; paths of more than one edge received: 12717 37:11:14.238 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 200000 reads 37:11:24.014 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 4 of 50000 reads. 37:16:32.438 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 46877 of them longer than 500; among long reads aligned: 45681; paths of more than one edge received: 13944 37:16:32.942 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 250000 reads 37:16:42.459 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 5 of 50000 reads. 37:23:21.148 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 46828 of them longer than 500; among long reads aligned: 45584; paths of more than one edge received: 14031 37:23:21.636 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 300000 reads 37:23:30.380 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 6 of 50000 reads. 37:28:28.466 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 46411 of them longer than 500; among long reads aligned: 45186; paths of more than one edge received: 13552 37:28:28.932 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 350000 reads 37:28:38.586 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 7 of 50000 reads. 37:35:22.323 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 45992 of them longer than 500; among long reads aligned: 44688; paths of more than one edge received: 13034 37:35:22.814 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 400000 reads 37:35:31.059 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 8 of 50000 reads. 37:40:24.319 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 44995 of them longer than 500; among long reads aligned: 43722; paths of more than one edge received: 12475 37:40:24.785 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 450000 reads 37:40:32.694 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 9 of 50000 reads. 37:45:27.669 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 43378 of them longer than 500; among long reads aligned: 42095; paths of more than one edge received: 11277 37:45:28.131 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 500000 reads 37:45:36.481 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 10 of 50000 reads. 37:52:05.934 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 45356 of them longer than 500; among long reads aligned: 44049; paths of more than one edge received: 12847 37:52:06.409 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 550000 reads 37:52:14.845 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 11 of 50000 reads. 37:59:12.654 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 46616 of them longer than 500; among long reads aligned: 45274; paths of more than one edge received: 13613 37:59:13.162 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 600000 reads 37:59:24.079 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 12 of 50000 reads. 38:06:45.174 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 46745 of them longer than 500; among long reads aligned: 45529; paths of more than one edge received: 14104 38:06:45.743 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 650000 reads 38:06:56.766 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 13 of 50000 reads. 38:14:39.241 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 46451 of them longer than 500; among long reads aligned: 45129; paths of more than one edge received: 13734 38:14:39.736 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 700000 reads 38:14:51.438 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 14 of 50000 reads. 38:20:51.356 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 47261 of them longer than 500; among long reads aligned: 46028; paths of more than one edge received: 14532 38:20:51.877 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 750000 reads 38:21:01.415 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 15 of 50000 reads. 38:26:43.775 86G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 47160 of them longer than 500; among long reads aligned: 45914; paths of more than one edge received: 14214 38:26:44.325 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 800000 reads 38:26:56.787 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 16 of 50000 reads. 38:32:57.558 86G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 50000 processed; 47048 of them longer than 500; among long reads aligned: 45848; paths of more than one edge received: 14300 38:32:58.134 86G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 850000 reads 38:33:05.825 85G / 122G INFO General (hybrid_aligning.cpp : 279) Prepared batch 17 of 44399 reads. 38:37:42.512 85G / 122G INFO General (hybrid_aligning.cpp : 241) Read batch of size: 44399 processed; 41444 of them longer than 500; among long reads aligned: 40391; paths of more than one edge received: 11820 38:37:42.961 85G / 122G INFO General (hybrid_aligning.cpp : 284) Processed 894399 reads 38:37:43.109 85G / 122G INFO General (hybrid_aligning.cpp : 313) For library of long reads 38:37:43.227 85G / 122G INFO StatsCounter (pacbio_read_structures.hpp: 165) Median fraction of present seeds in maximal alignmnent among reads aligned to the graph: 0 38:37:43.351 85G / 122G INFO General (hybrid_aligning.cpp : 315) Aligning of long reads finished 38:37:44.646 81G / 122G INFO HybridAligning (hybrid_aligning.cpp : 393) Padding gaps 38:37:44.779 81G / 122G INFO HybridAligning (hybrid_aligning.cpp : 397) Min gap weight set to 2 38:37:44.905 81G / 122G INFO General (hybrid_aligning.cpp : 151) Closing gaps with long reads 38:37:49.940 81G / 122G INFO MultiGapJoiner (hybrid_gap_closer.hpp : 559) Closed 404 gaps 38:37:55.352 81G / 122G INFO General (hybrid_aligning.cpp : 172) Closing gaps with long reads finished 38:37:55.491 81G / 122G INFO StageManager (stage.cpp : 189) STAGE == Paired Information Counting (id: late_pair_info_count) 38:38:19.214 89G / 122G INFO General (graph_pack_helpers.cpp : 54) Normalizing k-mer map. Total 446257493 kmers to process 38:41:41.316 89G / 122G INFO General (graph_pack_helpers.cpp : 56) Normalizing done 38:41:44.339 89G / 122G INFO General (pair_info_count.cpp : 157) Min edge length for estimation: 180 38:41:44.461 89G / 122G INFO General (pair_info_count.cpp : 168) Estimating insert size for library #0 38:41:44.572 89G / 122G INFO General (pair_info_count.cpp : 41) Selecting usual mapper 38:41:44.677 89G / 122G INFO General (paired_info_utils.cpp : 87) Estimating insert size (takes a while) 38:41:49.697 90G / 122G INFO General (sequence_mapper_notifier.h: 64) Starting sequence mapping 38:42:15.796 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 200000 reads 38:42:17.393 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 400000 reads 38:42:18.152 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 600000 reads 38:42:18.228 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 800000 reads 38:42:18.358 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 1000000 reads 38:42:18.421 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 1200000 reads 38:42:18.976 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 2200000 reads 38:42:19.354 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 4200000 reads 38:42:47.023 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 8400000 reads 38:43:17.237 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 16800000 reads 38:44:21.780 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 33600000 reads 38:46:43.256 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 67200000 reads 38:51:25.737 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 134400000 reads 39:00:46.462 90G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 268600000 reads 39:06:12.122 90G / 122G INFO General (sequence_mapper_notifier.h: 103) Total 329565923 reads processed 39:06:12.389 90G / 122G INFO General (paired_info_utils.cpp : 104) Edge pairs: 2964557282 39:06:12.523 90G / 122G INFO General (paired_info_utils.cpp : 106) 51227208 paired reads (15.5438% of all) aligned to long edges 39:06:12.739 89G / 122G INFO General (pair_info_count.cpp : 188) Insert size = 296.023, deviation = 107.831, left quantile = 166, right quantile = 439, read length = 150 39:06:12.874 89G / 122G INFO General (pair_info_count.cpp : 203) Filtering data for library #0 39:06:12.997 89G / 122G INFO General (pair_info_count.cpp : 41) Selecting usual mapper 39:06:20.741 97G / 122G INFO General (sequence_mapper_notifier.h: 64) Starting sequence mapping 39:07:03.369 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 200000 reads 39:07:20.157 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 400000 reads 39:07:26.546 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 600000 reads 39:07:26.546 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 800000 reads 39:07:26.546 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 1000000 reads 39:07:26.546 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 1200000 reads 39:07:26.547 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 2200000 reads 39:07:26.548 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 4200000 reads 39:08:25.157 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 8400000 reads 39:09:26.157 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 16800000 reads 39:11:32.283 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 33600000 reads 39:16:30.312 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 67200000 reads 39:25:51.064 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 134400000 reads 39:44:44.689 97G / 122G INFO General (sequence_mapper_notifier.h: 85) Processed 268600000 reads 39:54:20.861 97G / 122G INFO General (sequence_mapper_notifier.h: 103) Total 329565923 reads processed 39:54:21.363 97G / 122G INFO General (pair_info_count.cpp : 207) Mapping library #0 39:54:21.497 97G / 122G INFO General (pair_info_count.cpp : 209) Mapping paired reads (takes a while) 39:54:21.626 97G / 122G INFO General (pair_info_count.cpp : 41) Selecting usual mapper 39:54:21.748 97G / 122G INFO General (paired_info_utils.cpp : 138) Left insert size quantile 166, right insert size quantile 439, filtering threshold 2, rounding threshold 0 39:54:26.054 97G / 122G INFO General (sequence_mapper_notifier.h: 64) Starting sequence mapping 39:57:01.808 98G / 124G INFO General (sequence_mapper_notifier.h: 85) Processed 200000 reads 39:57:10.814 99G / 125G INFO General (sequence_mapper_notifier.h: 85) Processed 400000 reads 39:57:11.680 99G / 125G INFO General (sequence_mapper_notifier.h: 85) Processed 600000 reads 39:57:12.347 100G / 125G INFO General (sequence_mapper_notifier.h: 85) Processed 800000 reads 39:57:13.498 101G / 125G INFO General (sequence_mapper_notifier.h: 85) Processed 1000000 reads 39:57:13.559 102G / 126G INFO General (sequence_mapper_notifier.h: 85) Processed 1200000 reads 39:57:19.636 102G / 126G INFO General (sequence_mapper_notifier.h: 85) Processed 2200000 reads 39:57:26.528 103G / 127G INFO General (sequence_mapper_notifier.h: 85) Processed 4200000 reads 40:00:06.564 104G / 140G INFO General (sequence_mapper_notifier.h: 85) Processed 8400000 reads 40:03:01.652 106G / 152G INFO General (sequence_mapper_notifier.h: 85) Processed 16800000 reads 40:09:47.948 108G / 173G INFO General (sequence_mapper_notifier.h: 85) Processed 33600000 reads 40:24:46.413 110G / 207G INFO General (sequence_mapper_notifier.h: 85) Processed 67200000 reads 40:52:50.100 115G / 251G INFO General (sequence_mapper_notifier.h: 85) Processed 134400000 reads 41:50:24.648 121G / 314G INFO General (sequence_mapper_notifier.h: 85) Processed 268600000 reads 42:18:01.805 335G / 340G INFO General (sequence_mapper_notifier.h: 103) Total 329565923 reads processed 42:18:31.863 326G / 341G INFO General (pair_info_count.cpp : 161) Library #1 was mapped earlier on hybrid aligning stage, skipping 42:18:32.019 326G / 341G INFO StageManager (stage.cpp : 189) STAGE == Distance Estimation (id: distance_estimation) 42:18:32.190 326G / 341G INFO General (distance_estimation.cpp : 42) Processing library #0 42:18:32.353 326G / 341G INFO General (distance_estimation_utils.: 133) Weight Filter Done 42:18:32.530 326G / 341G INFO DistanceEstimator (distance_estimation.hpp : 116) Using SIMPLE distance estimator mimalloc: error: thread 0x7f294b7af640: unable to allocate OS memory (67108864 bytes, error code: 12 [Cannot allocate memory], address: (nil), large only: 0, allow large: 1) mimalloc: process info: elapsed: 160563.809 s process: user: 1224599.957 s, system: 14503.077 s, faults: 26306211 rss: current: 579801792512, peak: 480573063168 commit: current: 579801792512, peak: 579801792512 == Error == system call for: "['/home/denis/miniconda3/envs/S_pades/bin/spades-core', '/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/config.info', '/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/isolate_mode.info']" finished abnormally, OS return value: -6 None ======= SPAdes pipeline finished abnormally and WITH WARNINGS! === Error correction and assembling warnings: * 0:00:00.028 1M / 18M WARN StageManager (stage.cpp : 162) No saved checkpoint ======= Warnings saved to /home/denis/data/Pot_Spades_assembly/Spades_PA_out/warnings.log === ERRORs: * 1:35:39.164 9053M / 9053M ERROR General (kmer_splitter.hpp : 151) I/O error! Incomplete write! Reason: No space left on device. Error code: 28 * system call for: "['/home/denis/miniconda3/envs/S_pades/bin/spades-core', '/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K33/configs/config.info', '/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K33/configs/isolate_mode.info']" finished abnormally, OS return value: 28 * system call for: "['/home/denis/miniconda3/envs/S_pades/bin/spades-core', '/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/config.info', '/home/denis/data/Pot_Spades_assembly/Spades_PA_out/K77/configs/isolate_mode.info']" finished abnormally, OS return value: -6 In case you have troubles running SPAdes, you can report an issue on our GitHub repository github.com/ablab/spades Please provide us with params.txt and spades.log files from the output directory. SPAdes log can be found here: /home/denis/data/Pot_Spades_assembly/Spades_PA_out/spades.log Thank you for using SPAdes! If you use it in your research, please cite: Prjibelski, A., Antipov, D., Meleshko, D., Lapidus, A. and Korobeynikov, A., 2020. Using SPAdes de novo assembler. Current protocols in bioinformatics, 70(1), p.e102. doi.org/10.1002/cpbi.102