DamageProfiler crashes due to insufficient memory

[lucventurini]

Dear @apeltzer , unfortunately @hesterjvs and I have to report another bug related to the size of our reference! This time it was DamageProfiler that bit the dust.
As always, thank you for your kind support!

Describe the bug
DamageProfiler dies due to insufficient heap space when launched on barley (H. vulgare).
Error log:

ERROR ~ Error executing process > 'damageprofiler (Sample1_R1.sorted)'

Caused by:
  Process `damageprofiler (Sample1_R1.sorted)` terminated with an error exit status (1)

Command executed:
  damageprofiler -i Sample1_R1.sorted.bam -r Hordeum_vulgare.IBSC_v2.dna.toplevel.fa -l 100 -t 15 -o .

Command exit status:
  1

Command output:
  DamageProfiler v0.4.4

Command error:
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:11405:14721:10375 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:11406:5002:16779 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:11512:16287:4338 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:11608:24847:6528 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:11611:5298:6461 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:21404:15188:5553 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:21506:19502:6932 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:21512:21843:12310 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:21512:15250:14777 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:4:21612:25889:14924 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. NS500271:138:HCWHCAFXY:1:21308:16008:11412 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. NS500271:138:HCWHCAFXY:2:11311:24713:2848 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. NS500271:138:HCWHCAFXY:2:21311:22652:8074 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. NS500271:138:HCWHCAFXY:3:21504:15584:18433 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. NS500271:138:HCWHCAFXY:4:21405:23195:1235 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:11106:5563:17322 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:11204:21462:7413 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:11206:22621:3706 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:11302:3388:17203 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:11311:18926:15802 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:21101:22010:7840 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:21102:25863:9838 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:21205:19417:6307 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:21207:10269:10981 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:21210:16889:5902 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:21306:20256:11844 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:1:21311:7574:11681 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:11104:20740:4161 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:11105:13250:4866 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:11202:3292:6857 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:11211:13546:1080 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:11312:22862:17775 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:21104:9475:6822 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:21106:20766:19872 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:21204:17642:9593 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:21211:1333:10007 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:21303:12413:19100 record bin field value is incorrect.
  WARNING       2019-03-07 22:18:02     SAMRecord       chr4H reference length is too large for BAM bin field. M_NS500271:138:HCWHCAFXY:2:21307:5495:5636 record bin field value is incorrect.
  Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at java.util.Arrays.copyOf(Arrays.java:3181)
        at java.util.ArrayList.grow(ArrayList.java:261)
        at java.util.ArrayList.ensureExplicitCapacity(ArrayList.java:235)
        at java.util.ArrayList.ensureCapacityInternal(ArrayList.java:227)
        at java.util.ArrayList.add(ArrayList.java:458)
        at calculations.LengthDistribution.fillDistributionTable(LengthDistribution.java:61)
        at calculations.DamageProfiler.processRecord(DamageProfiler.java:217)
        at calculations.DamageProfiler.handleRecord(DamageProfiler.java:140)
        at calculations.DamageProfiler.extractSAMRecords(DamageProfiler.java:104)
        at calculations.StartCalculations.start(StartCalculations.java:258)
        at RunDamageProfiler.main(RunDamageProfiler.java:37)

Operating System:

• OS: Ubuntu 18.04

nextflow.log

[apeltzer]

Hm, this might be possible to adjust by adding e.g. a custom amount of memory to the respective process and then calling DamageProfiler accordingly. As I'm lacking this big data atm, can you test this on your side maybe?

1.) Checkout code locally by cloning the repository.
2.) Add something that uses the amount of memory required in the process damageprofiler scope e.g.:

damageprofiler -Xms1g -Xmx4g ... 

3.) Check whether it improves the situation by using the modified source in your call of nf-core/eager, e.g.

nextflow run nf-core/eager ... 
#now 
nextflow run ./eager/main.nf ... 

If this doesn't help too much, I'm afraid that I might have to ask Judith Neukamm upstream in the DamageProfiler project on how to deal with such big data or whether we tested that already (I doubt it, its fairly rare type of dat ;-))

[lucventurini]

Hi @apeltzer , trying it today, thanks for the suggestion!

[lucventurini]

Hi @apeltzer , so we tried again with higher memory settings, but DamageProfiler fails again.

The problem in this case is not due to memory, rather, DamageProfiler gets killed because it takes longer than 2 hours. I already tried changing the parameter on the command line (--max_time 12h) and looking at the log (which I attach) Eager correctly sets it. However, the DamageProfiler process is still assigned only 2 hours to complete, which is too little for our analysis.

On another related, but very important, note: it took us two days to perform these tests because eager does not restart correctly when instructed to resume. Rather, it almost always seems to restart from scratch, and sometimes instead it uses some of the cached processes. It is puzzling and quite time-consuming, because we have to wait for the pipeline to redo yet again all the steps before being able to verify the changes. Has this behaviour been observed and reported by any other experimenter? We might be doing something wrong, but we are at loss regarding what.

Command line:
eager --pairedEnd --bwa_index /data/references/Hordeum/ --fasta /data/references/Hordeum/Hordeum_vulgare.IBSC_v2.dna.toplevel.fa --reads '*_R{1,2}.fastq' --clip_forward_adaptor AGATCGGAAGAGCACACGTCTGAACTCCAGTCAC --clip_reverse_adaptor AGATCGGAAGAGCGTCGTGTAGGGAAAGAGTGTAGATCTCGGTGGTCGCCGTATCATT -resume --resume --large_ref --max_time 12.h

Thank you for your help!
nextflow.log

[apeltzer]

Hi @lucventurini!

the --max_time 12h parameter will only be used to run no job longer than this. The default for DamageProfiler is set to be 2 hours, so it will just increase that to 4h in case of failure and then fail if this is not successful.

eager --pairedEnd --bwa_index /data/references/Hordeum/ --fasta /data/references/Hordeum/Hordeum_vulgare.IBSC_v2.dna.toplevel.fa --reads '*_R{1,2}.fastq' --clip_forward_adaptor AGATCGGAAGAGCACACGTCTGAACTCCAGTCAC --clip_reverse_adaptor AGATCGGAAGAGCGTCGTGTAGGGAAAGAGTGTAGATCTCGGTGGTCGCCGTATCATT -resume  --large_ref --max_time 12.h

The single-dash -resume command should be sufficient --resume isn't doing anything. The rerunning of most parts is due to some issues we have with the reference indices being created a bit differently when specifying both bwa_index and the fasta file. It might be a bit of a similar issue than here: #150 , but I'll have to investigate a little and figure out whats going on there....

I will use the --large_ref switch to update DamageProfilers runtime to be 6-8h for large reference genome data - that should help and resolve the issue.

[lucventurini]

Hi @apeltzer ,
thank you for the reply! For the time being, until issue #150 is solved, we will remove the bwa_index from the command line. The --resume is there mainly because, out of desperation, I tried putting both flags (with one or two dashes) in, in the hope that either would function.

Thank you for changing instead the time for damageprofiler. That should hopefully solve the issue at hand.

[apeltzer]

Yeah, I know - happened to me quite a bunch of times now too. I'll have a look at making this a bit less annoying, especially with the indices etc. The current solution isn't optimal but this should be possible to be resolved.

I opened a PR for review, but you can already test the changes if you want to:

nextflow run apeltzer/eager -r apeltzer:damageprofiler-more [...]

[apeltzer]

And again, thanks for providing valuable feedback like this - it really helps a lot!

[lucventurini]

Hi @apeltzer ,
unfortunately we are not there yet ... the time limit is really too low for our genome. This time, it was BWA index which died because it exceeded the two hour limit. We could provide Eager the BWA index ourselves, as we did so far, but then we would lose the -resume capability, with the problems discussed above.

Would you be able to modify this? I have been trying to modify the source code directly but I seem not to be able to do the right correction (I will be interested in seeing the amended code later!)

[apeltzer]

Sorry, pretty crowded with work recently: Please test again on the same branch - this was just extended to 8hours for the indexing. I'm typically not testing on such large genomes :-(

[lucventurini]

Hi @apeltzer ,
not a problem, we understand!
Unfortunately the fix does not seem to work. I attach the .netflow.log file.
Best

Luca
nextflow.log

[jfy133]

@lucventurini having a quick look - could you try renaming the file reference suffix to .fasta? Alex is trying to find a way make the pipeline to accept other suffixes but it's not trivial it seems.

[lucventurini]

Hi @jfy133 , just tried, unfortunately it does not make any difference - Eager crashes with the same error as the previous log.

[apeltzer]

I'll have a look asap - can you provide me with the reference genome fasta or give me an id for that one? Then I can test myself and adjust accordingly...

[lucventurini]

Hi @apeltzer, sorry for the late reply, I had a full day! We are using the EnsEMBL version of the Hordeum vulgare genome, ie this file:

ftp://ftp.ensemblgenomes.org/pub/plants/release-42/fasta/hordeum_vulgare/dna/Hordeum_vulgare.IBSC_v2.dna.toplevel.fa.gz

Thank you!