Bogart failed

[angross]

Hi,
I'm having a similar issue like #546: #546
The assembly step stops with the following error:

--
-- CITATIONS
--
-- Koren S, Walenz BP, Berlin K, Miller JR, Phillippy AM.
-- Canu: scalable and accurate long-read assembly via adaptive k-mer weighting and repeat separation.
-- Genome Res. 2017 May;27(5):722-736.
-- http://doi.org/10.1101/gr.215087.116
-- 
-- Read and contig alignments during correction, consensus and GFA building use:
--   Šošic M, Šikic M.
--   Edlib: a C/C ++ library for fast, exact sequence alignment using edit distance.
--   Bioinformatics. 2017 May 1;33(9):1394-1395.
--   http://doi.org/10.1093/bioinformatics/btw753
-- 
-- Overlaps are generated using:
--   Berlin K, et al.
--   Assembling large genomes with single-molecule sequencing and locality-sensitive hashing.
--   Nat Biotechnol. 2015 Jun;33(6):623-30.
--   http://doi.org/10.1038/nbt.3238
-- 
--   Myers EW, et al.
--   A Whole-Genome Assembly of Drosophila.
--   Science. 2000 Mar 24;287(5461):2196-204.
--   http://doi.org/10.1126/science.287.5461.2196
-- 
--   Li H.
--   Minimap and miniasm: fast mapping and de novo assembly for noisy long sequences.
--   Bioinformatics. 2016 Jul 15;32(14):2103-10.
--   http://doi.org/10.1093/bioinformatics/btw152
-- 
-- Corrected read consensus sequences are generated using an algorithm derived from FALCON-sense:
--   Chin CS, et al.
--   Phased diploid genome assembly with single-molecule real-time sequencing.
--   Nat Methods. 2016 Dec;13(12):1050-1054.
--   http://doi.org/10.1038/nmeth.4035
-- 
-- Contig consensus sequences are generated using an algorithm derived from pbdagcon:
--   Chin CS, et al.
--   Nonhybrid, finished microbial genome assemblies from long-read SMRT sequencing data.
--   Nat Methods. 2013 Jun;10(6):563-9
--   http://doi.org/10.1038/nmeth.2474
-- 
-- CONFIGURE CANU
--
-- Detected Java(TM) Runtime Environment '1.8.0_45' (from '/tools/java/jre1.8.0_45/bin/java').
-- Detected gnuplot version '4.2 patchlevel 6 ' (from 'gnuplot') and image format 'png'.
-- Detected 40 CPUs and 252 gigabytes of memory.
-- Limited to 100G gigabytes from maxMemory option.
-- Limited to 8 CPUs from maxThreads option.
-- Detected Sun Grid Engine in '/SGE/ogs/default'.
-- User supplied Grid Engine environment '-pe parallel_smp THREADS'.
-- Detected Grid Engine consumable 'memoire'.
-- 
-- Found   1 host  with  64 cores and 1009 GB memory under Sun Grid Engine control.
-- Found   1 host  with 240 cores and 2932 GB memory under Sun Grid Engine control.
-- Found   1 host  with  20 cores and  252 GB memory under Sun Grid Engine control.
-- Found  67 hosts with  40 cores and  252 GB memory under Sun Grid Engine control.
--
--                     (tag)Threads
--            (tag)Memory         |
--        (tag)         |         |  algorithm
--        -------  ------  --------  -----------------------------
-- Grid:  meryl     25 GB    4 CPUs  (k-mer counting)
-- Grid:  cormhap   13 GB    4 CPUs  (overlap detection with mhap)
-- Grid:  obtovl     8 GB    4 CPUs  (overlap detection)
-- Grid:  utgovl     8 GB    4 CPUs  (overlap detection)
-- Grid:  cor       20 GB    4 CPUs  (read correction)
-- Grid:  ovb        4 GB    1 CPU   (overlap store bucketizer)
-- Grid:  ovs        8 GB    1 CPU   (overlap store sorting)
-- Grid:  red        6 GB    4 CPUs  (read error detection)
-- Grid:  oea        2 GB    1 CPU   (overlap error adjustment)
-- Grid:  bat       25 GB    4 CPUs  (contig construction)
-- Grid:  cns       25 GB    4 CPUs  (consensus)
-- Grid:  gfa        8 GB    4 CPUs  (GFA alignment and processing)
--
-- Found PacBio corrected reads in 'unitigging/Assembly_1.gkpStore'.
--
-- Generating assembly 'Assembly_1' in '/work/project/mildew/Assembly1'
--
-- Parameters:
--
--  genomeSize        100000000
--
--  Overlap Generation Limits:
--    corOvlErrorRate 0.2400 ( 24.00%)
--    obtOvlErrorRate 0.0450 (  4.50%)
--    utgOvlErrorRate 0.0450 (  4.50%)
--
--  Overlap Processing Limits:
--    corErrorRate    0.3000 ( 30.00%)
--    obtErrorRate    0.0450 (  4.50%)
--    utgErrorRate    0.0450 (  4.50%)
--    cnsErrorRate    0.0750 (  7.50%)
--
--
-- BEGIN ASSEMBLY
--
--
-- Bogart failed, tried 2 times, giving up.
--

ABORT:
ABORT: Canu 1.6
ABORT: Don't panic, but a mostly harmless error occurred and Canu stopped.
ABORT: Try restarting.  If that doesn't work, ask for help.
ABORT:
Your job has been killed.
This may happen if one of the followings hold : 
- you exceeded one of the queue/job limits (run time, memory, etc)
- you (or admin) killed the job using qdel 
- something bad happened. 
Now, just in case something bad happened, here are the debug information about your job : 
total 0
JOB INFO : 
total 44
-rw-r--r-- 1 sgeadmin sgeadmin    34 Dec  1 14:29 pe_hostfile
-rw-r--r-- 1 sgeadmin sgeadmin 11911 Dec  1 14:29 environment
-rw-r--r-- 1 sgeadmin sgeadmin  2313 Dec  1 14:29 config
-rw-r--r-- 1 sgeadmin sgeadmin     6 Dec  1 14:29 pid
-rw-r--r-- 1 sgeadmin sgeadmin     6 Dec  1 14:29 job_pid
-rw-r--r-- 1 sgeadmin sgeadmin     6 Dec  1 14:29 addgrpid
-rw-r--r-- 1 agross   UMR1202      0 Dec  1 14:29 exit_status
-rw-r--r-- 1 agross   UMR1202      0 Dec  1 14:29 error
-rw-r--r-- 1 sgeadmin sgeadmin   318 Dec  1 14:29 usage
-rw-r--r-- 1 agross   UMR1202   4781 Dec  1 14:29 trace
STATUS : 
TRACE : 
12/01/2017 14:29:19 [500:69993]: shepherd called with uid = 0, euid = 500
12/01/2017 14:29:19 [500:69993]: starting up 2011.11p1
12/01/2017 14:29:19 [500:69993]: setpgid(69993, 69993) returned 0
12/01/2017 14:29:19 [500:69993]: do_core_binding: "binding" parameter not found in config file
12/01/2017 14:29:19 [500:69993]: no prolog script to start
12/01/2017 14:29:19 [500:69993]: no pe_start script to start
12/01/2017 14:29:19 [500:69993]: parent: forked "job" with pid 69994
12/01/2017 14:29:19 [500:69993]: parent: job-pid: 69994
12/01/2017 14:29:19 [500:69994]: child: starting son(job, /var/spool/sge/node006/job_scripts/4746155, 0);
12/01/2017 14:29:19 [500:69994]: pid=69994 pgrp=69994 sid=69994 old pgrp=69993 getlogin()=<no login set>
12/01/2017 14:29:19 [500:69994]: reading passwd information for user 'agross'
12/01/2017 14:29:19 [500:69994]: setosjobid: uid = 0, euid = 500
12/01/2017 14:29:19 [500:69994]: setting limits
12/01/2017 14:29:19 [500:69994]: RLIMIT_CPU setting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY)) resulting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY))
12/01/2017 14:29:19 [500:69994]: RLIMIT_FSIZE setting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY)) resulting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY))
12/01/2017 14:29:19 [500:69994]: RLIMIT_DATA setting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY)) resulting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY))
12/01/2017 14:29:19 [500:69994]: RLIMIT_STACK setting: (soft 268435456, hard 268435456) resulting: (soft 268435456, hard 268435456)
12/01/2017 14:29:19 [500:69994]: RLIMIT_CORE setting: (soft 0, hard 0) resulting: (soft 0, hard 0)
12/01/2017 14:29:19 [500:69994]: RLIMIT_MEMLOCK setting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY)) resulting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY))
12/01/2017 14:29:19 [500:69994]: RLIMIT_VMEM/RLIMIT_AS setting: (soft 8589934592, hard 8589934592) resulting: (soft 8589934592, hard 8589934592)
12/01/2017 14:29:19 [500:69994]: RLIMIT_RSS setting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY)) resulting: (soft 18446744073709551615(INFINITY), hard 18446744073709551615(INFINITY))
12/01/2017 14:29:19 [500:69994]: setting environment
12/01/2017 14:29:19 [500:69994]: Initializing error file
12/01/2017 14:29:19 [500:69994]: switching to intermediate/target user
12/01/2017 14:29:19 [14660:69994]: closing all filedescriptors
12/01/2017 14:29:19 [14660:69994]: further messages are in "error" and "trace"
12/01/2017 14:29:19 [14660:69994]: using stdout as stderr
12/01/2017 14:29:19 [14660:69994]: now running with uid=14660, euid=14660
12/01/2017 14:29:19 [14660:69994]: execvp(/var/spool/sge/node006/job_scripts/4746155, "/var/spool/sge/node006/job_scripts/4746155")
12/01/2017 14:29:22 [500:69993]: wait3 returned 69994 (status: 256; WIFSIGNALED: 0,  WIFEXITED: 1, WEXITSTATUS: 1)
12/01/2017 14:29:22 [500:69993]: job exited with exit status 1
12/01/2017 14:29:22 [500:69993]: reaped "job" with pid 69994
12/01/2017 14:29:22 [500:69993]: job exited not due to signal
12/01/2017 14:29:22 [500:69993]: job exited with status 1
12/01/2017 14:29:22 [500:69993]: now sending signal KILL to pid -69994
12/01/2017 14:29:22 [500:69993]: writing usage file to "usage"
12/01/2017 14:29:22 [500:69993]: no tasker to notify
12/01/2017 14:29:22 [500:69993]: no pe_stop script to start
12/01/2017 14:29:22 [500:69993]: parent: forked "epilog" with pid 70127
12/01/2017 14:29:22 [500:69993]: using signal delivery delay of 120 seconds
12/01/2017 14:29:22 [500:69993]: parent: epilog-pid: 70127
12/01/2017 14:29:22 [500:70127]: child: starting son(epilog, /SGE/ogs/inra/tools/epilog_verbose.sh, 0);
12/01/2017 14:29:22 [500:70127]: pid=70127 pgrp=70127 sid=70127 old pgrp=69993 getlogin()=<no login set>
12/01/2017 14:29:22 [500:70127]: reading passwd information for user 'agross'
12/01/2017 14:29:22 [500:70127]: setting limits
12/01/2017 14:29:22 [500:70127]: setting environment
12/01/2017 14:29:22 [500:70127]: Initializing error file
12/01/2017 14:29:22 [500:70127]: switching to intermediate/target user
12/01/2017 14:29:22 [14660:70127]: closing all filedescriptors
12/01/2017 14:29:22 [14660:70127]: further messages are in "error" and "trace"
12/01/2017 14:29:22 [14660:70127]: using "/bin/bash" as shell of user "agross"
12/01/2017 14:29:22 [14660:70127]: using stdout as stderr
12/01/2017 14:29:22 [14660:70127]: now running with uid=14660, euid=14660
12/01/2017 14:29:22 [14660:70127]: execvp(/SGE/ogs/inra/tools/epilog_verbose.sh, "/SGE/ogs/inra/tools/epilog_verbose.sh")
ERROR : 
Messages file :
End debugging information.
Epilog : job finished at Fri Dec  1 14:29:29 CET 2017

Because I read that the unitigger.err file could be important to solve the problem, I also attach it here:

Resources:
  Memory                25 GB
  Compute Threads       4 (command line)

Lengths:
  Minimum read          0 bases
  Minimum overlap       500 bases

Overlap Error Rates:
  Graph                 0.045 (4.500%)
  Max                   0.045 (4.500%)

Deviations:
  Graph                 6.000
  Bubble                6.000
  Repeat                3.000

Edge Confusion:
  Absolute              2100
  Percent               200.0000

Unitig Construction:
  Minimum intersection  500 bases
  Maxiumum placements   2 positions

Debugging Enabled:
  (none)

==> LOADING AND FILTERING OVERLAPS.

ReadInfo()-- Using 954643 reads, no minimum read length used.

OverlapCache()-- limited to 25600MB memory (user supplied).

OverlapCache()--       7MB for read data.
OverlapCache()--      36MB for best edges.
OverlapCache()--      94MB for tigs.
OverlapCache()--      25MB for tigs - read layouts.
OverlapCache()--      36MB for tigs - error profiles.
OverlapCache()--    6400MB for tigs - error profile overlaps.
OverlapCache()--       0MB for other processes.
OverlapCache()-- ---------
OverlapCache()--    6618MB for data structures (sum of above).
OverlapCache()-- ---------
OverlapCache()--      18MB for overlap store structure.
OverlapCache()--   18963MB for overlap data.
OverlapCache()-- ---------
OverlapCache()--   25600MB allowed.
OverlapCache()--
OverlapCache()-- Retain at least 70 overlaps/read, based on 35.48x coverage.
OverlapCache()-- Initial guess at 1301 overlaps/read.
OverlapCache()--
OverlapCache()-- Adjusting for sparse overlaps.
OverlapCache()--
OverlapCache()--               reads loading olaps          olaps               memory
OverlapCache()--   olaps/read       all      some          loaded                 free
OverlapCache()--   ----------   -------   -------     ----------- -------     --------
OverlapCache()--         1301    517418    437225       615422644  12.67%       9572 MB
OverlapCache()--         2735    529812    424831      1234265368  25.41%        129 MB
OverlapCache()--         2755    530077    424566      1242759559  25.58%          0 MB
OverlapCache()--
OverlapCache()-- Loading overlaps.
OverlapCache()--
OverlapCache()--          read from store           saved in cache
OverlapCache()--   ------------ ---------   ------------ ---------
OverlapCache()--      504456736 (010.39%)      125113686 (002.58%)
OverlapCache()--      973238122 (020.04%)      245797840 (005.06%)
OverlapCache()--     1427045622 (029.38%)      363928617 (007.49%)
OverlapCache()--     1892364969 (038.96%)      484613230 (009.98%)
OverlapCache()--     2418001048 (049.78%)      613334872 (012.63%)
OverlapCache()--     3001630838 (061.79%)      750768422 (015.46%)
OverlapCache()--     3535993019 (072.79%)      882505988 (018.17%)
OverlapCache()--     4048959685 (083.35%)     1012151317 (020.84%)
OverlapCache()--     4556016611 (093.79%)     1139890749 (023.47%)
OverlapCache()--   ------------ ---------   ------------ ---------
OverlapCache()--     4857497842 (100.00%)     1212567106 (024.96%)
OverlapCache()--
OverlapCache()-- Ignored 490239518 duplicate overlaps.
OverlapCache()--
OverlapCache()-- Symmetrizing overlaps.
OverlapCache()--   Finding missing twins.
OverlapCache()--   Found 676981120 missing twins in 1212567106 overlaps, 9623 are strong.
OverlapCache()--   Dropping weak non-twin overlaps; allocated 0 MB scratch space.
OverlapCache()--   Dropped 306637017 overlaps; scratch space released.
OverlapCache()--   Adding 370344103 missing twin overlaps.
OverlapCache()--   Finished.

BestOverlapGraph()-- allocating best edges (29MB)

BestOverlapGraph()-- finding initial best edges.

BestOverlapGraph()-- filtering suspicious reads.
BestOverlapGraph()-- marked 363 reads as suspicious.

BestOverlapGraph()-- filtering high error edges.

BestOverlapGraph()-- filtering reads with lopsided best edges.

BestOverlapGraph()-- filtering spur reads.
BestOverlapGraph()-- detected 19367 spur reads and 4185 singleton reads.

BestOverlapGraph()-- removing best edges for contained reads.

==> BUILDING GREEDY TIGS.

breakSingletonTigs()-- Removed 17349 singleton tigs; reads are now unplaced.
optimizePositions()-- Optimizing read positions for 22152 reads in 954644 tigs, with 4 threads.
optimizePositions()--   Allocating scratch space for 954644 reads (0 KB).
optimizePositions()--   Initializing positions with 4 threads.
optimizePositions()--   Recomputing positions, iteration 1, with 4 threads.
optimizePositions()--     Reset zero.
optimizePositions()--     Checking convergence.
optimizePositions()--     converged: 946184 reads
optimizePositions()--     changed:     8460 reads
optimizePositions()--   Recomputing positions, iteration 2, with 4 threads.
optimizePositions()--     Reset zero.
optimizePositions()--     Checking convergence.
optimizePositions()--     converged: 951172 reads
optimizePositions()--     changed:     3472 reads
optimizePositions()--   Recomputing positions, iteration 3, with 4 threads.
optimizePositions()--     Reset zero.
optimizePositions()--     Checking convergence.
optimizePositions()--     converged: 951333 reads
optimizePositions()--     changed:     3311 reads
optimizePositions()--   Recomputing positions, iteration 4, with 4 threads.
optimizePositions()--     Reset zero.
optimizePositions()--     Checking convergence.
optimizePositions()--     converged: 951405 reads
optimizePositions()--     changed:     3239 reads
optimizePositions()--   Recomputing positions, iteration 5, with 4 threads.
optimizePositions()--     Reset zero.
optimizePositions()--     Checking convergence.
optimizePositions()--     converged: 951445 reads
optimizePositions()--     changed:     3199 reads
optimizePositions()--   Expanding short reads with 4 threads.
optimizePositions()--   Updating positions.
optimizePositions()--   Finished.

==> PLACE CONTAINED READS.

computeErrorProfiles()-- Computing error profiles for 22152 tigs, with 4 threads.
computeErrorProfiles()-- Finished.

placeContains()-- placing 880813 contained and 28687 unplaced reads, with 4 threads.
placeContains()-- Placed 623978 contained reads and 1072 unplaced reads.
placeContains()-- Failed to place 256835 contained reads (too high error suspected) and 27615 unplaced reads (lack of overlaps suspected).
optimizePositions()-- Optimizing read positions for 22152 reads in 954644 tigs, with 4 threads.
optimizePositions()--   Allocating scratch space for 954644 reads (0 KB).
optimizePositions()--   Initializing positions with 4 threads.
bogart: bogart/AS_BAT_OptimizePositions.C:140: void Unitig::optimize_initPlace(uint32, optPos*, optPos*, bool, std::set<unsigned int>&, bool): Assertion `cnt > 0' failed.

Failed with 'Aborted'; backtrace (libbacktrace):
AS_UTL/AS_UTL_stackTrace.C::102 in _Z17AS_UTL_catchCrashiP7siginfoPv()
(null)::0 in (null)()
(null)::0 in (null)()
(null)::0 in (null)()
(null)::0 in (null)()
(null)::0 in (null)()
bogart/AS_BAT_OptimizePositions.C::140 in _ZN6Unitig18optimize_initPlaceEjP6optPosS1_bRSt3setIjSt4lessIjESaIjEEb()
bogart/AS_BAT_OptimizePositions.C::391 in _ZN9TigVector17optimizePositionsEPKcS1_._omp_fn.0()
../../../gcc-6.1.0/libgomp/team.c::119 in gomp_thread_start()
(null)::0 in (null)()
(null)::0 in (null)()
(null)::0 in (null)()

Do you have any idea what could be the problem? Any help is greatly appreciated!
Best Andrin

[angross]

My post is still unanswered so I wonder whether it was a really stupid question because the solution is obvious. At least I myself could still not figure out the mistake and I would really appreciate if somebody could give me a hint.
I’m working with a fungal genome and the quality of the data might be a problem. Read length was quite low but it was the best I could get.
Here is the command I’ve used:
-p Assembly_1
-d Assembly1
-pacbio-raw EQ_PacBio.fastq
genomeSize=100m
gridEngineThreadsOption="-pe parallel_smp THREADS"
minReadLength=1500
maxMemory=45G
StopOnReadQuality=False
maxThreads=25

[skoren]

This seems like an actual bug so it's not clear there is an easy workaround. It looks like bogart was limited to 25gb but you have machines with much larger memory so you could try setting batMemory=200 to see if that helps. You could try running bogart from 1.5, it should still work on the 1.6 data.

[brianwalenz]

This should be fixed (d580c23). Note that you CANNOT upgrade to the latest code and resume an assembly started with the 1.6 release.

Duplicate of #546.