search

nanoporetech / medaka

Sequence correction provided by ONT Research
https://nanoporetech.com
Other
391 stars 73 forks source link

[medaka_consensus] python: corrupted size vs. prev_size #400

Closed lxsteiner closed 1 year ago

lxsteiner commented 1 year ago

Describe the bug Ran medaka_consensus on a Flye assembly:

medaka_consensus -i READS.fq.gz -d flye-unpolished.fasta -o flye_medaka -m r941_min_sup_g507 -t 16
Checking program versions
This is medaka 1.7.2
Program    Version    Required   Pass
bcftools   1.16       1.11       True
bgzip      1.16       1.11       True
minimap2   2.24       2.11       True
samtools   1.16.1     1.11       True
tabix      1.16       1.11       True

near the end, showed the following errors:

python3.8/site-packages/medaka/labels.py:387: RuntimeWarning: divide by zero encountered in log10
  q = -10 * np.log10(err)
python': corrupted size vs. prev_size: 0x000055c86c5f0f80 ***
medaka_consensus: line 168: 31057 Aborted                 (core dumped) medaka stitch "${CONSENSUSPROBS}" "${DRAFT}" "${CONSENSUS}" --threads "${THREADS}" ${STITCH_OPTS}
Failed to stitch consensus chunks.

Logging

medaka_consensus -i READS.fq.gz -d flye-unpolished.fasta -o flye_medaka -m r941_min_sup_g507 -t 16
Checking program versions
This is medaka 1.7.2
Program    Version    Required   Pass
bcftools   1.16       1.11       True
bgzip      1.16       1.11       True
minimap2   2.24       2.11       True
samtools   1.16.1     1.11       True
tabix      1.16       1.11       True
Aligning basecalls to draft
Creating fai index file /media/5c679734-9376-4617-815c-d4bd4177b8b2/leon/projects/03/data/Hal144_assemblies/Hal144-lxs6_dragonflye/flye-unpolished.fasta.
fai
Creating mmi index file /media/5c679734-9376-4617-815c-d4bd4177b8b2/leon/projects/03/data/Hal144_assemblies/Hal144-lxs6_dragonflye/flye-unpolished.fasta.
map-ont.mmi
[M::mm_idx_gen::0.241*0.99] collected minimizers
[M::mm_idx_gen::0.297*1.34] sorted minimizers
[M::main::0.377*1.26] loaded/built the index for 2 target sequence(s)
[M::mm_idx_stat] kmer size: 15; skip: 10; is_hpc: 0; #seq: 2
[M::mm_idx_stat::0.391*1.26] distinct minimizers: 844636 (98.54% are singletons); average occurrences: 1.018; average spacing: 5.343; total length: 45918
61
[M::main] Version: 2.24-r1122
[M::main] CMD: minimap2 -I 16G -x map-ont -d /media/5c679734-9376-4617-815c-d4bd4177b8b2/leon/projects/03/data/Hal144_assemblies/Hal144-lxs6_dragonflye/f
lye-unpolished.fasta.map-ont.mmi /media/5c679734-9376-4617-815c-d4bd4177b8b2/leon/projects/03/data/Hal144_assemblies/Hal144-lxs6_dragonflye/flye-unpolished.fasta
[M::main] Real time: 0.400 sec; CPU: 0.500 sec; Peak RSS: 0.046 GB
[M::main::0.115*1.01] loaded/built the index for 2 target sequence(s)
[M::mm_mapopt_update::0.133*0.99] mid_occ = 10
[M::mm_idx_stat] kmer size: 15; skip: 10; is_hpc: 0; #seq: 2
[M::mm_idx_stat::0.146*0.99] distinct minimizers: 844636 (98.54% are singletons); average occurrences: 1.018; average spacing: 5.343; total length: 4591861
[M::worker_pipeline::18.689*9.17] mapped 46921 sequences
[M::main] Version: 2.24-r1122
[M::main] CMD: minimap2 -x map-ont --secondary=no -L --MD -A 2 -B 4 -O 4,24 -E 2,1 -t 16 -a /media/5c679734-9376-4617-815c-d4bd4177b8b2/leon/projects/03/data/Hal144_assemblies/Hal144-lxs6_dragonflye/flye-unpolished.fasta.map-ont.mmi /media/5c679734-9376-4617-815c-d4bd4177b8b2/leon/projects/03/data/Hal144_assemblies/Hal144-lxs6_dragonflye/READS.fq.gz
[M::main] Real time: 18.701 sec; CPU: 171.368 sec; Peak RSS: 4.146 GB
[bam_sort_core] merging from 0 files and 16 in-memory blocks...
Running medaka consensus
[13:33:42 - Predict] Reducing threads to 2, anymore is a waste.
[13:33:42 - Predict] It looks like you are running medaka without a GPU and attempted to set a high number of threads. We have scaled this down to an optimal number. If you wish to improve performance please see https://nanoporetech.github.io/medaka/installation.html#improving-parallelism.
[13:33:42 - Predict] Setting tensorflow inter/intra-op threads to 2/1.
[13:33:42 - Predict] Processing region(s): contig_1:0-4514726 contig_2:0-77135
[13:33:42 - Predict] Using model: /home/leon/miniconda3/envs/medaka_env/lib/python3.8/site-packages/medaka/data/r941_min_sup_g507_model.tar.gz.
[13:33:42 - Predict] Processing 6 long region(s) with batching.
[13:33:43 - MdlStrTF] Model <keras.engine.sequential.Sequential object at 0x7faf121a6c70>
[13:33:43 - MdlStrTF] loading weights from /tmp/tmput2fac2n/model/variables/variables
[13:33:43 - BAMFile] Creating pool of 16 BAM file sets.
[13:33:43 - Sampler] Initializing sampler for consensus of region contig_1:0-1000000.
[13:33:43 - Sampler] Initializing sampler for consensus of region contig_1:999000-1999000.
[13:33:43 - PWorker] Running inference for 4.6M draft bases.
[13:33:45 - Feature] Processed contig_1:0.0-999999.0 (median depth 53.0)
[13:33:45 - Sampler] Took 1.53s to make features.
[13:33:45 - Sampler] Initializing sampler for consensus of region contig_1:1998000-2998000.
[13:33:45 - Feature] Processed contig_1:999000.0-1998999.0 (median depth 56.0)
[13:33:45 - Sampler] Took 1.63s to make features.
[13:33:45 - Sampler] Initializing sampler for consensus of region contig_1:2997000-3997000.
[13:33:47 - Feature] Processed contig_1:2997000.0-3996999.0 (median depth 58.0)
[13:33:47 - Feature] Processed contig_1:1998000.0-2997999.0 (median depth 60.0)
[13:33:47 - Sampler] Took 1.68s to make features.
[13:33:47 - Sampler] Took 1.59s to make features.
[13:33:47 - Sampler] Initializing sampler for consensus of region contig_1:3996000-4514726.
[13:33:47 - Sampler] Initializing sampler for consensus of region contig_2:0-77135.
[13:33:47 - Feature] Processed contig_1:3996000.0-4514725.0 (median depth 54.0)
[13:33:47 - Sampler] Took 0.88s to make features.
[13:33:49 - Feature] Processed contig_2:0.0-77134.0 (median depth 522.0)
[13:33:49 - Sampler] Took 2.46s to make features.
[13:34:17 - PWorker] Batches in cache: 8.
[13:34:17 - PWorker] 10.2% Done (0.5/4.6 Mbases) in 33.8s
[13:34:41 - PWorker] Batches in cache: 8.
[13:34:41 - PWorker] 20.4% Done (0.9/4.6 Mbases) in 57.5s
[13:35:04 - PWorker] Batches in cache: 8.
[13:35:04 - PWorker] 30.3% Done (1.4/4.6 Mbases) in 81.1s
[13:35:28 - PWorker] Batches in cache: 8.
[13:35:28 - PWorker] 40.4% Done (1.9/4.6 Mbases) in 104.2s
[13:35:51 - PWorker] Batches in cache: 7.
[13:35:51 - PWorker] 50.2% Done (2.3/4.6 Mbases) in 127.8s
[13:36:15 - PWorker] Batches in cache: 6.
[13:36:15 - PWorker] 60.3% Done (2.8/4.6 Mbases) in 151.8s
[13:36:38 - PWorker] Batches in cache: 5.
[13:36:38 - PWorker] 70.3% Done (3.2/4.6 Mbases) in 174.7s
[13:37:02 - PWorker] Batches in cache: 4.
[13:37:02 - PWorker] 79.9% Done (3.7/4.6 Mbases) in 198.2s
[13:37:25 - PWorker] Batches in cache: 3.
[13:37:25 - PWorker] 89.6% Done (4.1/4.6 Mbases) in 221.5s
[13:37:48 - PWorker] Batches in cache: 2.
[13:37:48 - PWorker] 99.1% Done (4.6/4.6 Mbases) in 245.0s
[13:37:58 - PWorker] Batches in cache: 1.
[13:37:59 - PWorker] Processed 11 batches
[13:37:59 - PWorker] All done, 0 remainder regions.
[13:37:59 - Predict] Finished processing all regions.
[13:38:01 - DataIndx] Loaded 1/1 (100.00%) sample files.
[13:38:02 - DataIndx] Loaded 1/1 (100.00%) sample files.
[13:38:02 - DataIndx] Loaded 1/1 (100.00%) sample files.
[13:38:02 - DataIndx] Loaded 1/1 (100.00%) sample files.
[13:38:02 - DataIndx] Loaded 1/1 (100.00%) sample files.
[13:38:02 - DataIndx] Loaded 1/1 (100.00%) sample files.
[13:38:02 - DataIndx] Loaded 1/1 (100.00%) sample files.
/home/leon/miniconda3/envs/medaka_env/lib/python3.8/site-packages/medaka/labels.py:387: RuntimeWarning: divide by zero encountered in log10
  q = -10 * np.log10(err)
/home/leon/miniconda3/envs/medaka_env/lib/python3.8/site-packages/medaka/labels.py:387: RuntimeWarning: divide by zero encountered in log10
  q = -10 * np.log10(err)
/home/leon/miniconda3/envs/medaka_env/lib/python3.8/site-packages/medaka/labels.py:387: RuntimeWarning: divide by zero encountered in log10
  q = -10 * np.log10(err)
/home/leon/miniconda3/envs/medaka_env/lib/python3.8/site-packages/medaka/labels.py:387: RuntimeWarning: divide by zero encountered in log10
  q = -10 * np.log10(err)
/home/leon/miniconda3/envs/medaka_env/lib/python3.8/site-packages/medaka/labels.py:387: RuntimeWarning: divide by zero encountered in log10
  q = -10 * np.log10(err)
/home/leon/miniconda3/envs/medaka_env/lib/python3.8/site-packages/medaka/labels.py:387: RuntimeWarning: divide by zero encountered in log10
  q = -10 * np.log10(err)
*** Error in `/home/leon/miniconda3/envs/medaka_env/bin/python': corrupted size vs. prev_size: 0x000055c86c5f0f80 ***
/home/leon/miniconda3/envs/medaka_env/bin/medaka_consensus: line 168: 31057 Aborted                 (core dumped) medaka stitch "${CONSENSUSPROBS}" "${DRAFT}" "${CONSENSUS}" --threads "${THREADS}" ${STITCH_OPTS}
Failed to stitch consensus chunks.

Environment (if you do not have a GPU, write No GPU):

Additional context Is this related to #368 and can be ignored? I see output being produced but not sure how much I should trust it. 

-rw-rw-r-- 1 leon leon 318715699 Nov 24 13:33 calls_to_draft.bam
-rw-rw-r-- 1 leon leon    125280 Nov 24 13:33 calls_to_draft.bam.bai
-rw-rw-r-- 1 leon leon   4605592 Nov 24 13:38 consensus.fasta
-rw-rw-r-- 1 leon leon         0 Nov 24 13:38 consensus.fasta.gaps_in_draft_coords.bed
-rw-rw-r-- 1 leon leon 210200457 Nov 24 13:37 consensus_probs.hdf

The consensus also ended up being larger by a few kb:

File    #Seq    Total bp        Avg     N50     N75     N90     auN     Min     Max
consensus.fasta 2       4605570 2302785.0       4528256 4528256 4528256 4453537.750     77314   4528256
File    #Seq    Total bp        Avg     N50     N75     N90     auN     Min     Max
flye-unpolished.fasta        2       4591861 2295930.5       4514726 4514726 4514726 4440182.458     77135   4514726
lxsteiner commented 1 year ago

I ran this on another system I had also a conda installation of medaka:

This is medaka 1.4.3
Program    Version    Required   Pass
bcftools   1.12       1.11       True
bgzip      1.12       1.11       True
minimap2   2.21       2.11       True
samtools   1.12       1.11       True
tabix      1.12       1.11       True

and that finished miraculously:

Polished assembly written to flye_medaka/consensus.fasta, have a nice day.

This was on:

Red Hat Enterprise Linux 8.2 (Ootpa)

I had the same medaka version installed on the Ubuntu system and it was giving the same error as before. Then upgraded the medaka installation to the one in the first post, because it said in another issue that this seemed to help, but not in my case.

cjw85 commented 1 year ago

Sorry @lxsteiner,

I would strongly advise you to update your Ubuntu 14 machine to a newer version of the OS.

Are you saying v1.7.2 is broken on your RHEL 8.2 machine also?

cjw85 commented 1 year ago

Closing as stale.