PICARD MarkDuplicates errors near the end of its process: tmp does not exist

Hi, I have a problem in that PICARD MarkDuplicates appears to error near the end of its process -- with a temp file not found error.

This is running in a GATK pipeline on our cluster for WGS Best Practices.

Error is;
Exception in thread "main" java.lang.IllegalStateException: Non-zero numRecords but /tmp/rwillia/CSPI.7224120933399878689.tmp/2.tmp does not exist

We get the same error with picard 2.9.2 and picard 2.0.1 . The java being used is:
java version "1.8.0_65"
Java(TM) SE Runtime Environment (build 1.8.0_65-b17)
Java HotSpot(TM) 64-Bit Server VM (build 25.65-b01, mixed mode)

We have tried multiple different BAM files as tests and get the same error.

Has anybody else seen this "tmp does not exist error" before? Was there a fix that worked?I cannot see this error previously reported.
I can run MarkDuplicates using a standalone Qsub tester script and I get the same error.

I made the directory /tmp/rwillia on the scratch drive but it did not help.
Thanks for any help,
Cheers,
Roy Williams

Test qsub script

PBS -l walltime=99:00:00

PBS -l nodes=1:ppn=8:memory=29gb

export TMPDIR=/scratch/rwillia
module load samtools
module load picard
java -Xmx26g -jar /opt/applications/picard/2.1.0/bin/picard.jar MarkDuplicates \
I=/mnt/loring/data/OMICS_PIPE_DATA/ANALYSIS/DNAseq/RW_WGS/BWA_RESULTS/REACH000450/REACH000450_sorted.rg.bam \
O=/mnt/loring/data/OMICS_PIPE_DATA/ANALYSIS/DNAseq/RW_WGS/BWA_RESULTS/REACH000450/REACH000450_sorted.rg.md.bam \
M=/mnt/loring/data/OMICS_PIPE_DATA/ANALYSIS/DNAseq/RW_WGS/BWA_RESULTS/REACH000450/REACH000450_sorted.rg.md.metrics.txt \
ASSUME_SORTED=true \
VALIDATION_STRINGENCY=LENIENT

picard.sam.markduplicates.MarkDuplicates done. Elapsed time: 14.35 minutes.
Runtime.totalMemory()=21026570240
To get help, see http://broadinstitute.github.io/picard/index.html#GettingHelp
Exception in thread "main" java.lang.IllegalStateException: Non-zero numRecords but /tmp/rwillia/CSPI.7224120933399878689.tmp/2.tmp does not exist
at htsjdk.samtools.CoordinateSortedPairInfoMap.ensureSequenceLoaded(CoordinateSortedPairInfoMap.java:141)
at htsjdk.samtools.CoordinateSortedPairInfoMap.remove(CoordinateSortedPairInfoMap.java:86)
at picard.sam.markduplicates.util.DiskBasedReadEndsForMarkDuplicatesMap.remove(DiskBasedReadEndsForMarkDuplicatesMap.java:61)
at picard.sam.markduplicates.MarkDuplicates.buildSortedReadEndLists(MarkDuplicates.java:388)
at picard.sam.markduplicates.MarkDuplicates.doWork(MarkDuplicates.java:185)
at picard.cmdline.CommandLineProgram.instanceMain(CommandLineProgram.java:209)
at picard.cmdline.PicardCommandLine.instanceMain(PicardCommandLine.java:95)
at picard.cmdline.PicardCommandLine.main(PicardCommandLine.java:105)

Roy Williams, Ph.D.
Bioinformatics Director,
The Center for Regenerative Medicine,
Scripps Research Institute,
10550 North Torrey Pines Road
San Diego, California, 92121
USA

Best Answer

Answers

  • Hi, I got a very similar error:

    Exception in thread "Thread-1" Exception in thread "Thread-2" htsjdk.samtools.util.RuntimeIOException: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.8727540578515832395.tmp

    Changing the tmp directory didn't work. I only get this error on the cluster, I used multiple computers before and all was fine.

    Any idea?

    Thanks,
    Zsuzsa

  • SheilaSheila Broad InstituteMember, Broadie, Moderator admin

    @gerzs
    Hi Zsuzsa,

    Can you post the entire log output with the error message? This thread may also help.

    -Sheila

  • @Sheila
    Here it is.

    [Tue Feb 06 16:16:45 CET 2018] MarkDuplicates INPUT=[01_normal.rg_added_sorted.bam] OUTPUT=01_normal.dedupped.bam METRICS_FILE=01_normal.output.metrics VALIDATION_STRINGENCY=SILENT CREATE_INDEX=true    MAX_SEQUENCES_FOR_DISK_READ_ENDS_MAP=50000 MAX_FILE_HANDLES_FOR_READ_ENDS_MAP=8000 SORTING_COLLECTION_SIZE_RATIO=0.25 TAG_DUPLICATE_SET_MEMBERS=false REMOVE_SEQUENCING_DUPLICATES=false TAGGING_POLICY=DontTag CLEAR_DT=true ADD_PG_TAG_TO_READS=true REMOVE_DUPLICATES=false ASSUME_SORTED=false DUPLICATE_SCORING_STRATEGY=SUM_OF_BASE_QUALITIES PROGRAM_RECORD_ID=MarkDuplicates PROGRAM_GROUP_NAME=MarkDuplicates READ_NAME_REGEX=<optimized capture of last three ':' separated fields as numeric values> OPTICAL_DUPLICATE_PIXEL_DISTANCE=100 MAX_OPTICAL_DUPLICATE_SET_SIZE=300000 VERBOSITY=INFO QUIET=false COMPRESSION_LEVEL=5 MAX_RECORDS_IN_RAM=500000 CREATE_MD5_FILE=false GA4GH_CLIENT_SECRETS=client_secrets.json USE_JDK_DEFLATER=false USE_JDK_INFLATER=false
    INFO    2018-02-06 16:16:45     MarkDuplicates  Start of doWork freeMemory: 1000672008; totalMemory: 1015021568; maxMemory: 15036579840
    INFO    2018-02-06 16:16:45     MarkDuplicates  Reading input file and constructing read end information.
    INFO    2018-02-06 16:16:45     MarkDuplicates  Will retain up to 54480361 data points before spilling to disk.
    INFO    2018-02-06 16:16:50     MarkDuplicates  Read     1,000,000 records.  Elapsed time: 00:00:04s.  Time for last 1,000,000:    4s.  Last read position: 1:568,007
    INFO    2018-02-06 16:16:50     MarkDuplicates  Tracking 3908 as yet unmatched pairs. 3908 records in RAM.
    INFO    2018-02-06 16:16:54     MarkDuplicates  Read     2,000,000 records.  Elapsed time: 00:00:08s.  Time for last 1,000,000:    3s.  Last read position: 1:8,925,418
    INFO    2018-02-06 16:16:54     MarkDuplicates  Tracking 3637 as yet unmatched pairs. 3637 records in RAM.
    INFO    2018-02-06 16:16:58     MarkDuplicates  Read     3,000,000 records.  Elapsed time: 00:00:12s.  Time for last 1,000,000:    4s.  Last read position: 1:21,177,854
    INFO    2018-02-06 16:16:58     MarkDuplicates  Tracking 161 as yet unmatched pairs. 161 records in RAM.
    INFO    2018-02-06 16:17:02     MarkDuplicates  Read     4,000,000 records.  Elapsed time: 00:00:16s.  Time for last 1,000,000:    3s.  Last read position: 1:29,435,887
    INFO    2018-02-06 16:17:02     MarkDuplicates  Tracking 108 as yet unmatched pairs. 108 records in RAM.
    ...
    ...
    INFO    2018-02-06 16:32:03     MarkDuplicates  Tracking 17953 as yet unmatched pairs. 17953 records in RAM.
    INFO    2018-02-06 16:32:07     MarkDuplicates  Read   155,000,000 records.  Elapsed time: 00:15:21s.  Time for last 1,000,000:    3s.  Last read position: X:56,592,082
    INFO    2018-02-06 16:32:07     MarkDuplicates  Tracking 96 as yet unmatched pairs. 96 records in RAM.
    INFO    2018-02-06 16:32:10     MarkDuplicates  Read   156,000,000 records.  Elapsed time: 00:15:24s.  Time for last 1,000,000:    3s.  Last read position: X:118,784,031
    INFO    2018-02-06 16:32:10     MarkDuplicates  Tracking 135 as yet unmatched pairs. 135 records in RAM.
    INFO    2018-02-06 16:32:13     MarkDuplicates  Read   157,000,000 records.  Elapsed time: 00:15:27s.  Time for last 1,000,000:    2s.  Last read position: X:153,627,859
    INFO    2018-02-06 16:32:13     MarkDuplicates  Tracking 16249 as yet unmatched pairs. 16249 records in RAM.
    INFO    2018-02-06 16:32:17     MarkDuplicates  Read   158,000,000 records.  Elapsed time: 00:15:31s.  Time for last 1,000,000:    4s.  Last read position: GL000220.1:114,732
    INFO    2018-02-06 16:32:17     MarkDuplicates  Tracking 19027 as yet unmatched pairs. 19027 records in RAM.
    INFO    2018-02-06 16:32:23     MarkDuplicates  Read   159,000,000 records.  Elapsed time: 00:15:37s.  Time for last 1,000,000:    5s.  Last read position: GL000220.1:117,192
    INFO    2018-02-06 16:32:23     MarkDuplicates  Tracking 24346 as yet unmatched pairs. 24346 records in RAM.
    INFO    2018-02-06 16:32:25     MarkDuplicates  Read   160,000,000 records.  Elapsed time: 00:15:39s.  Time for last 1,000,000:    1s.  Last read position: GL000220.1:159,041
    INFO    2018-02-06 16:32:25     MarkDuplicates  Tracking 962 as yet unmatched pairs. 962 records in RAM.
    INFO    2018-02-06 16:32:26     MarkDuplicates  Read 160893220 records. 0 pairs never matched.
    INFO    2018-02-06 16:32:50     MarkDuplicates  After buildSortedReadEndLists freeMemory: 7832978384; totalMemory: 7902068736; maxMemory: 15036579840
    INFO    2018-02-06 16:32:50     MarkDuplicates  Will retain up to 469893120 duplicate indices before spilling to disk.
    INFO    2018-02-06 16:32:50     MarkDuplicates  Traversing read pair information and detecting duplicates.
    INFO    2018-02-06 16:33:15     MarkDuplicates  Traversing fragment information and detecting duplicates.
    INFO    2018-02-06 16:33:51     MarkDuplicates  Sorting list of duplicate records.
    INFO    2018-02-06 16:33:53     MarkDuplicates  After generateDuplicateIndexes freeMemory: 6710938968; totalMemory: 10551296000; maxMemory: 15036579840
    INFO    2018-02-06 16:33:53     MarkDuplicates  Marking 40567544 records as duplicates.
    INFO    2018-02-06 16:33:53     MarkDuplicates  Found 4464 optical duplicate clusters.
    INFO    2018-02-06 16:33:53     MarkDuplicates  Reads are assumed to be ordered by: coordinate
    INFO    2018-02-06 16:35:04     MarkDuplicates  Written    10,000,000 records.  Elapsed time: 00:01:10s.  Time for last 10,000,000:   70s.  Last read position: 1:153,587,157
    INFO    2018-02-06 16:36:15     MarkDuplicates  Written    20,000,000 records.  Elapsed time: 00:02:21s.  Time for last 10,000,000:   70s.  Last read position: 11:836,076
    INFO    2018-02-06 16:37:27     MarkDuplicates  Written    30,000,000 records.  Elapsed time: 00:03:33s.  Time for last 10,000,000:   72s.  Last read position: 12:48,238,231
    INFO    2018-02-06 16:38:37     MarkDuplicates  Written    40,000,000 records.  Elapsed time: 00:04:43s.  Time for last 10,000,000:   70s.  Last read position: 14:50,862,434
    INFO    2018-02-06 16:39:47     MarkDuplicates  Written    50,000,000 records.  Elapsed time: 00:05:53s.  Time for last 10,000,000:   69s.  Last read position: 15:49,170,746
    INFO    2018-02-06 16:40:57     MarkDuplicates  Written    60,000,000 records.  Elapsed time: 00:07:03s.  Time for last 10,000,000:   70s.  Last read position: 17:1,422,714
    INFO    2018-02-06 16:42:08     MarkDuplicates  Written    70,000,000 records.  Elapsed time: 00:08:14s.  Time for last 10,000,000:   70s.  Last read position: 18:74,073,226
    INFO    2018-02-06 16:43:17     MarkDuplicates  Written    80,000,000 records.  Elapsed time: 00:09:23s.  Time for last 10,000,000:   69s.  Last read position: 19:45,883,068
    INFO    2018-02-06 16:44:27     MarkDuplicates  Written    90,000,000 records.  Elapsed time: 00:10:33s.  Time for last 10,000,000:   69s.  Last read position: 2:174,773,725
    INFO    2018-02-06 16:45:37     MarkDuplicates  Written   100,000,000 records.  Elapsed time: 00:11:43s.  Time for last 10,000,000:   69s.  Last read position: 22:23,243,510
    INFO    2018-02-06 16:46:46     MarkDuplicates  Written   110,000,000 records.  Elapsed time: 00:12:52s.  Time for last 10,000,000:   69s.  Last read position: 4:25,279,832
    INFO    2018-02-06 16:47:56     MarkDuplicates  Written   120,000,000 records.  Elapsed time: 00:14:02s.  Time for last 10,000,000:   69s.  Last read position: 6:29,857,175
    INFO    2018-02-06 16:49:06     MarkDuplicates  Written   130,000,000 records.  Elapsed time: 00:15:12s.  Time for last 10,000,000:   69s.  Last read position: 7:47,317,545
    INFO    2018-02-06 16:50:15     MarkDuplicates  Written   140,000,000 records.  Elapsed time: 00:16:21s.  Time for last 10,000,000:   69s.  Last read position: 9:80,031,554
    INFO    2018-02-06 16:51:23     MarkDuplicates  Written   150,000,000 records.  Elapsed time: 00:17:29s.  Time for last 10,000,000:   67s.  Last read position: MT:8,787
    INFO    2018-02-06 16:52:31     MarkDuplicates  Written   160,000,000 records.  Elapsed time: 00:18:37s.  Time for last 10,000,000:   67s.  Last read position: GL000220.1:159,041
    INFO    2018-02-06 16:53:20     MarkDuplicates  Before output close freeMemory: 10813608480; totalMemory: 10902044672; maxMemory: 15036579840
    INFO    2018-02-06 16:53:20     MarkDuplicates  After output close freeMemory: 10822521376; totalMemory: 10910957568; maxMemory: 15036579840
    [Tue Feb 06 16:53:20 CET 2018] picard.sam.markduplicates.MarkDuplicates done. Elapsed time: 36.59 minutes.
    Runtime.totalMemory()=10910957568
    Exception in thread "Thread-3" Exception in thread "Thread-1" Exception in thread "Thread-4" htsjdk.samtools.util.RuntimeIOException: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.178361
    3708333674783.tmp
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:374)
    Caused by: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.1783613708333674783.tmp
            at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
            at sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:244)
            at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
            at java.nio.file.Files.delete(Files.java:1126)
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:372)
    htsjdk.samtools.util.RuntimeIOException: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.5794426837337854145.tmp
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:374)
    Caused by: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.5794426837337854145.tmp
            at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
            at sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:244)
            at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
            at java.nio.file.Files.delete(Files.java:1126)
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:372)
    htsjdk.samtools.util.RuntimeIOException: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.7463755976594655646.tmp
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:374)
    Caused by: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.7463755976594655646.tmp
            at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
            at sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:244)
            at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
            at java.nio.file.Files.delete(Files.java:1126)
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:372)
    Exception in thread "Thread-5" Exception in thread "Thread-2" htsjdk.samtools.util.RuntimeIOException: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.5502800916888055658.tmp
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:374)
    Caused by: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.5502800916888055658.tmp
            at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
            at sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:244)
            at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
            at java.nio.file.Files.delete(Files.java:1126)
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:372)
    htsjdk.samtools.util.RuntimeIOException: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.5249905139884905786.tmp
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:374)
    Caused by: java.nio.file.NoSuchFileException: /tmp/gerzs/sortingcollection.5249905139884905786.tmp
            at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
            at sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:244)
            at sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:103)
            at java.nio.file.Files.delete(Files.java:1126)
            at htsjdk.samtools.util.IOUtil$DeletePathThread.run(IOUtil.java:372)
    
  • SheilaSheila Broad InstituteMember, Broadie, Moderator admin

    @gerzs
    Hi,

    The NoSuchFileException part tells me the file does not exist. Can you post the exact command you ran? Are you using multiple threads?

    Thanks,
    Sheila

  • jreevejreeve Member
    I was having a similar issue when I tried running MarkDuplicates on a species that had a scaffold level reference genome. In my case MarkDuplicates was trying to open more temporary files than my server could manage (use `ulimit -n` to find the limit). I fixed this issue by setting the option `MAX_FILE_HANDLES_FOR_READ_ENDS_MAP=1000`. This limits the number of open files at the same time (default = 8000), however it also runs a bit slower.

    You can also do this by increasing `MAX_RECORDS_IN_RAM` which will run faster than the previous option, but use a lot more memory.
  • bhanuGandhambhanuGandham Cambridge MAMember, Administrator, Broadie, Moderator admin

    Hi @jreeve

    Thanks for sharing the info with us.This might be of help to other users.

Sign In or Register to comment.