"java.lang.NullPointerException" error

Dear developers,
So recently I encountered "java.lang.NullPointerException" error, when dealing with 400+ samples in the SVDiscovery step. It was divided into 300+ jobs, and about 30 jobs failed due to this error. After I reran the jobs, about 15 of them worked, and the remaining ones still failed due to the same error. Simply rerunning the job again helps a bit, but the most the remaining jobs still failed.

Here is the one example error:

ERROR 11:12:08,761 FunctionEdge - Error:  'java'  '-Xmx4096m'  '-XX:+UseParallelOldGC'  '-XX:ParallelGCThreads=4'  '-XX:GCTimeLimit=50'  '-XX:GCHeapFreeLimit=10'  '-Djava.io.tmpdir=/u/home/h/hjzhou/.queue/tmp'  '-cp' '/u/home/a/alden/svtoolkit/lib/SVToolkit.jar:/u/home/a/alden/svtoolkit/lib/gatk/GenomeAnalysisTK.jar:/u/home/a/alden/svtoolkit/lib/gatk/Queue.jar' org.broadinstitute.sv.main.SVDiscovery '-T' 'SVDiscoveryWalker'  '-R' '/u/home/a/alden/eeskin2/bipolar_sv/svtoolkit/reference/Homo_sapiens_assembly19.fasta'  '-I' '/u/home/h/hjzhou/batch_redo449.list'  '-O' '/u/flashscratch/h/hjzhou/redo_discovery_out/deletions100k.svtoolkit2017April.mask/P0263.discovery.vcf.gz'  '-disableGATKTraversal' 'true'  '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.0/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.1/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.2/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.3/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.4/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.0/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.1/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.2/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.3/metadata' '-md' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.4/metadata'  '-configFile' '/u/home/a/alden/svtoolkit/conf/genstrip_parameters.txt'  '-runDirectory' '/u/flashscratch/h/hjzhou/redo_discovery_out/deletions100k.svtoolkit2017April.mask'  '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.0/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.1/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.2/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.3/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.4/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.0/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.1/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.2/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.3/metadata/sample_gender.report.txt' '-genderMapFile' '/u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.4/metadata/sample_gender.report.txt'  '-genomeMaskFile' '/u/home/a/alden/eeskin2/bipolar_sv/svtoolkit/reference/Homo_sapiens_assembly19.svmask.fasta'  '-partitionName' 'P0263'  '-runFilePrefix' 'P0263'  '-storeReadPairFile' 'true'  -L chr17:19997001-30103001 -searchLocus chr17:20000001-30000000 -searchWindow chr17:19997001-30103001 -searchMinimumSize 100 -searchMaximumSize 100000
ERROR 11:12:08,770 FunctionEdge - Contents of /u/flashscratch/h/hjzhou/redo_discovery_out/deletions100k.svtoolkit2017April.mask/logs/SVDiscovery-263.out:
INFO  11:07:06,817 HelpFormatter - -----------------------------------------------------------------------------------------
INFO  11:07:06,821 HelpFormatter - The Genome Analysis Toolkit (GATK) v3.5.GS-r1732-0-gf101448, Compiled 2017/04/18 15:39:27
INFO  11:07:06,821 HelpFormatter - Copyright (c) 2010 The Broad Institute
INFO  11:07:06,821 HelpFormatter - For support and documentation go to http://www.broadinstitute.org/gatk
INFO  11:07:06,826 HelpFormatter - Program Args: -T SVDiscoveryWalker -R /u/home/a/alden/eeskin2/bipolar_sv/svtoolkit/reference/Homo_sapiens_assembly19.fasta -O /u/flashscratch/h/hjzhou/redo_discovery_out/deletions100k.svtoolkit2017April.mask/P0263.discovery.vcf.gz -disableGATKTraversal true -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.0/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.1/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.2/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.3/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.4/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.0/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.1/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.2/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.3/metadata -md /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.4/metadata -configFile /u/home/a/alden/svtoolkit/conf/genstrip_parameters.txt -runDirectory /u/flashscratch/h/hjzhou/redo_discovery_out/deletions100k.svtoolkit2017April.mask -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.0/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.1/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.2/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.3/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.4/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.0/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.1/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.2/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.3/metadata/sample_gender.report.txt -genderMapFile /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.4/metadata/sample_gender.report.txt -genomeMaskFile /u/home/a/alden/eeskin2/bipolar_sv/svtoolkit/reference/Homo_sapiens_assembly19.svmask.fasta -partitionName P0263 -runFilePrefix P0263 -storeReadPairFile true -L chr17:19997001-30103001 -searchLocus chr17:20000001-30000000 -searchWindow chr17:19997001-30103001 -searchMinimumSize 100 -searchMaximumSize 100000
INFO  11:07:06,833 HelpFormatter - Executing as [email protected] on Linux 2.6.32-696.18.7.el6.x86_64 amd64; Java HotSpot(TM) 64-Bit Server VM 1.8.0_111-b14.
INFO  11:07:06,833 HelpFormatter - Date/Time: 2018/06/07 11:07:06
INFO  11:07:06,833 HelpFormatter - -----------------------------------------------------------------------------------------
INFO  11:07:06,834 HelpFormatter - -----------------------------------------------------------------------------------------
INFO  11:07:07,133 07-Jun-2018 GenomeAnalysisEngine - Strictness is SILENT
INFO  11:07:07,236 07-Jun-2018 GenomeAnalysisEngine - Downsampling Settings: No downsampling
INFO  11:07:07,256 07-Jun-2018 IntervalUtils - Processing 10106001 bp from intervals
INFO  11:07:07,354 07-Jun-2018 GenomeAnalysisEngine - Preparing for traversal
INFO  11:07:07,356 07-Jun-2018 GenomeAnalysisEngine - Done preparing for traversal
INFO  11:07:07,356 07-Jun-2018 ProgressMeter - [INITIALIZATION COMPLETE; STARTING PROCESSING]
INFO  11:07:07,356 07-Jun-2018 ProgressMeter -                 | processed |    time |    per 1M |           |   total | remaining
INFO  11:07:07,356 07-Jun-2018 ProgressMeter -        Location |     reads | elapsed |     reads | completed | runtime |   runtime
INFO  11:07:07,357 07-Jun-2018 SVDiscovery - Initializing SVDiscovery ...
INFO  11:07:07,357 07-Jun-2018 SVDiscovery - Reading configuration file ...
INFO  11:07:07,362 07-Jun-2018 SVDiscovery - Read configuration file.
INFO  11:07:07,362 07-Jun-2018 SVDiscovery - Opening reference sequence ...
INFO  11:07:07,362 07-Jun-2018 SVDiscovery - Opened reference sequence.
INFO  11:07:07,363 07-Jun-2018 SVDiscovery - Opening genome mask ...
INFO  11:07:07,364 07-Jun-2018 SVDiscovery - Opened genome mask.
INFO  11:07:07,364 07-Jun-2018 SVDiscovery - Initializing input data set ...
INFO  11:07:11,540 07-Jun-2018 SVDiscovery - Initialized data set: 449 files, 449 read groups, 449 samples.
INFO  11:07:11,541 07-Jun-2018 MetaData - Opening metadata ...
INFO  11:07:11,543 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.0/metadata ...
INFO  11:07:11,543 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.1/metadata ...
INFO  11:07:11,544 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.2/metadata ...
INFO  11:07:11,545 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.3/metadata ...
INFO  11:07:11,546 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch1.4/metadata ...
INFO  11:07:11,547 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.0/metadata ...
INFO  11:07:11,548 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.1/metadata ...
INFO  11:07:11,549 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.2/metadata ...
INFO  11:07:11,549 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.3/metadata ...
INFO  11:07:11,550 07-Jun-2018 MetaData - Adding metadata directory /u/flashscratch/h/hjzhou/bipolar_sv_large/batch2.4/metadata ...
INFO  11:07:11,567 07-Jun-2018 MetaData - Opened metadata.
INFO  11:07:11,580 07-Jun-2018 SVDiscovery - Opened metadata.
INFO  11:07:11,586 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,615 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,629 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,641 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,653 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,669 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,680 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,692 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,704 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:11,716 07-Jun-2018 MetaData - Loading insert size distributions ...
INFO  11:07:12,023 07-Jun-2018 SVDiscovery - Processing locus: chr17:20000001-30000000:100-100000
INFO  11:07:12,023 07-Jun-2018 SVDiscovery - Locus search window: chr17:19997001-30103001
INFO  11:07:37,361 07-Jun-2018 ProgressMeter -        Starting         0.0    30.0 s      49.6 w      100.0%    30.0 s       0.0 s
INFO  11:08:07,363 07-Jun-2018 ProgressMeter -        Starting         0.0    60.0 s      99.2 w      100.0%    60.0 s       0.0 s
INFO  11:08:37,364 07-Jun-2018 ProgressMeter -        Starting         0.0    90.0 s     148.8 w      100.0%    90.0 s       0.0 s
INFO  11:09:07,365 07-Jun-2018 ProgressMeter -        Starting         0.0   120.0 s     198.4 w      100.0%   120.0 s       0.0 s
INFO  11:09:37,367 07-Jun-2018 ProgressMeter -        Starting         0.0     2.5 m     248.0 w      100.0%     2.5 m       0.0 s
INFO  11:10:07,870 07-Jun-2018 ProgressMeter -        Starting         0.0     3.0 m     298.5 w      100.0%     3.0 m       0.0 s
INFO  11:10:37,885 07-Jun-2018 ProgressMeter -        Starting         0.0     3.5 m     348.1 w      100.0%     3.5 m       0.0 s
INFO  11:11:07,886 07-Jun-2018 ProgressMeter -        Starting         0.0     4.0 m     397.7 w      100.0%     4.0 m       0.0 s
INFO  11:11:37,887 07-Jun-2018 ProgressMeter -        Starting         0.0     4.5 m     447.3 w      100.0%     4.5 m       0.0 s
Caught exception while processing read: HS2000-9109_119:4:1305:6758:46890       97      chr17   22253156        3       29M1I70M        =       22260357        7296    GTTGGAAACGGGATAAACCGCACAGAACTAAAACAGAAGCATTCTAAGAACCCTCTTCGTGATGTTTGCATTCAACTCACAGTGCTGAACCTTTCTTTGA    AABDDDEEA<[email protected]:AB?CBBC?BJCCC>[email protected][email protected]@CBBACABBCB?CBCADCACBDDCDADEDDCFEEDC    MD:Z:44C6T23C7T15       RG:Z:LP6005646-DNA_A12  NM:i:5  AS:i:72 XS:i:67
INFO  11:11:43,073 07-Jun-2018 GATKRunReport - Uploaded run statistics report to AWS S3
##### ERROR ------------------------------------------------------------------------------------------
##### ERROR stack trace
java.lang.NullPointerException
        at htsjdk.samtools.SAMRecordQueryNameComparator.fileOrderCompare(SAMRecordQueryNameComparator.java:76)
        at htsjdk.samtools.SAMRecordQueryNameComparator.compare(SAMRecordQueryNameComparator.java:32)
        at htsjdk.samtools.SAMRecordQueryNameComparator.compare(SAMRecordQueryNameComparator.java:29)
        at java.util.TimSort.countRunAndMakeAscending(TimSort.java:355)
        at java.util.TimSort.sort(TimSort.java:234)
        at java.util.Arrays.sort(Arrays.java:1512)
        at htsjdk.samtools.util.SortingCollection$InMemoryIterator.<init>(SortingCollection.java:350)
        at htsjdk.samtools.util.SortingCollection.iterator(SortingCollection.java:269)
        at htsjdk.samtools.SAMFileWriterImpl.close(SAMFileWriterImpl.java:213)
        at org.broadinstitute.sv.discovery.DeletionDiscoveryAlgorithm.closeOutputFiles(DeletionDiscoveryAlgorithm.java:1217)
        at org.broadinstitute.sv.discovery.DeletionDiscoveryAlgorithm.close(DeletionDiscoveryAlgorithm.java:120)
        at org.broadinstitute.sv.discovery.SVDiscoveryWalker.onTraversalDone(SVDiscoveryWalker.java:109)
        at org.broadinstitute.sv.discovery.SVDiscoveryWalker.onTraversalDone(SVDiscoveryWalker.java:40)
        at org.broadinstitute.gatk.engine.executive.Accumulator$StandardAccumulator.finishTraversal(Accumulator.java:129)
        at org.broadinstitute.gatk.engine.executive.LinearMicroScheduler.execute(LinearMicroScheduler.java:116)
        at org.broadinstitute.gatk.engine.GenomeAnalysisEngine.execute(GenomeAnalysisEngine.java:315)
        at org.broadinstitute.gatk.engine.CommandLineExecutable.execute(CommandLineExecutable.java:121)
        at org.broadinstitute.sv.main.SVCommandLine.execute(SVCommandLine.java:133)
        at org.broadinstitute.gatk.utils.commandline.CommandLineProgram.start(CommandLineProgram.java:248)
        at org.broadinstitute.gatk.utils.commandline.CommandLineProgram.start(CommandLineProgram.java:155)
        at org.broadinstitute.sv.main.SVCommandLine.main(SVCommandLine.java:87)
        at org.broadinstitute.sv.main.SVDiscovery.main(SVDiscovery.java:21)
##### ERROR ------------------------------------------------------------------------------------------
##### ERROR A GATK RUNTIME ERROR has occurred (version 3.5.GS-r1732-0-gf101448):
##### ERROR
##### ERROR This might be a bug. Please check the documentation guide to see if this is a known problem.
##### ERROR If not, please post the error message, with stack trace, to the GATK forum.
##### ERROR Visit our website and forum for extensive documentation and answers to
##### ERROR commonly asked questions http://www.broadinstitute.org/gatk
##### ERROR
##### ERROR MESSAGE: Code exception (see stack trace for error itself)
##### ERROR ------------------------------------------------------------------------------------------
INFO  11:12:08,771 QGraph - Writing incremental jobs reports...
INFO  11:12:08,771 QJobsReporter - Writing JobLogging GATKReport to file /u/home/h/hjzhou/SVDiscovery.jobreport.txt
INFO  11:12:08,797 QGraph - 5 Pend, 12 Run, 1 Fail, 310 Done

In the error, the read associating with a particular partition is not always the same (in most cases, it is different). I wonder what might be the cause.

Answers

  • bhandsakerbhandsaker Member, Broadie, Moderator admin

    This was pretty puzzling, but after poring over the stack trace I have some ideas about what is going on.

    You say that you see a different read associated with each error. Does this mean that in the "Caught exception while processing read:" line you see different reads when you rerun the same partition?
    I'm assuming that's what you mean and that this is accurate.

    The rest of the stack trace is (unfortunately) from a secondary error that is happening when the code is trying to clean up from the original exception. It is unclear what the cause of the secondary error is, but the stack trace from the original exception is currently being lost (because the cleanup is in a finally clause). If it is happening on different reads, then it is probably something transient like running out of temp file space or something like that. It looks like you are not passing a -tempDir argument to SVDiscovery. You might try setting that to a directory with plenty of free space (and also maybe set java.io.tmpdir just to be safe).

    I will try to fix the code so that exceptions are not getting swallowed in this scenario in future releases.

  • hjzhouhjzhou Member

    Thank you very much! You understand correctly. After I added "-tempDir", it works! I really appreciate it.

Sign In or Register to comment.