To celebrate the release of GATK 4.0, we are giving away free credits for running the GATK4 Best Practices pipelines in FireCloud, our secure online analysis portal. It’s first come first serve, so sign up now to claim your free credits worth $250. Sponsored by Google Cloud. Learn more at https://software.broadinstitute.org/firecloud/documentation/freecredits

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

Answers

  • SheilaSheila Broad InstituteMember, Broadie, Moderator

    @royw
    Hi Roy,

    This seems like a system error. If you run the Picard command on a subset of data and run it on your own computer, does the issue still occur?

    Thanks,
    Sheila

  • gerzsgerzs Member

    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

    @gerzs
    Hi Zsuzsa,

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

    -Sheila

  • gerzsgerzs Member

    @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

    @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

Sign In or Register to comment.