SortAndFixTags FileTruncatedException error Answered

Post author
Aspen Neuro

I've been running WGS samples through the "processing-for-variant-discovery-gatk4" workflow (snapshot 8). I've noticed that my samples consistently fail at the SortAndFixTags step, with the same error for the most part. Per this post, I had set maxRetries on SortAndFixTags to 3. I've also shared my workspace with GROUP_FireCloud-Support@firecloud.org

Strangely enough, I wasn't able to find this error code on any other FireCloud/Terra posts, so any help would be much appreciated! 

Example error log:

Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/cromwell_root/tmp.b8f37bb7
Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/cromwell_root/tmp.b8f37bb7
11:27:00.764 INFO NativeLibraryLoader - Loading libgkl_compression.so from jar:file:/gatk/gatk-package-4.1.0.0-local.jar!/com/intel/gkl/native/libgkl_compression.so
11:27:00.767 INFO NativeLibraryLoader - Loading libgkl_compression.so from jar:file:/gatk/gatk-package-4.1.0.0-local.jar!/com/intel/gkl/native/libgkl_compression.so
[Thu Jun 27 11:27:00 UTC 2019] SetNmMdAndUqTags --INPUT /dev/stdin --OUTPUT HDF111iPS501_D13_r2.hg38.aligned.duplicate_marked.sorted.bam --CREATE_INDEX true --CREATE_MD5_FILE true --REFERENCE_SEQUENCE /cromwell_root/broad-references/hg38/v0/Homo_sapiens_assembly38.fasta --IS_BISULFITE_SEQUENCE false --SET_ONLY_UQ false --VERBOSITY INFO --QUIET false --VALIDATION_STRINGENCY STRICT --COMPRESSION_LEVEL 5 --MAX_RECORDS_IN_RAM 500000 --GA4GH_CLIENT_SECRETS client_secrets.json --help false --version false --showHidden false --USE_JDK_DEFLATER false --USE_JDK_INFLATER false[Thu Jun 27 11:27:00 UTC 2019] SortSam --INPUT /cromwell_root/fc-2c60522a-326b-4267-94c5-f21b05441fc1/f9a48e87-a052-422b-b8ca-7c160d61392c/PreProcessingForVariantDiscovery_GATK4/ff1c88fa-ca88-427b-96f1-6377d32b1f48/call-MarkDuplicates/HDF111iPS501_D13_r2.hg38.aligned.unsorted.duplicates_marked.bam --OUTPUT /dev/stdout --SORT_ORDER coordinate --CREATE_INDEX false --CREATE_MD5_FILE false --VERBOSITY INFO --QUIET false --VALIDATION_STRINGENCY STRICT --COMPRESSION_LEVEL 5 --MAX_RECORDS_IN_RAM 500000 --GA4GH_CLIENT_SECRETS client_secrets.json --help false --version false --showHidden false --USE_JDK_DEFLATER false --USE_JDK_INFLATER false

[Thu Jun 27 11:27:01 UTC 2019] Executing as root@0843eed7a4ec on Linux 4.14.111+ amd64; OpenJDK 64-Bit Server VM 1.8.0_191-8u191-b12-0ubuntu0.16.04.1-b12; Deflater: Intel; Inflater: Intel; Provider GCS is available; Picard version: Version:4.1.0.0[Thu Jun 27 11:27:01 UTC 2019] Executing as root@0843eed7a4ec on Linux 4.14.111+ amd64; OpenJDK 64-Bit Server VM 1.8.0_191-8u191-b12-0ubuntu0.16.04.1-b12; Deflater: Intel; Inflater: Intel; Provider GCS is available; Picard version: Version:4.1.0.0

INFO 2019-06-27 11:30:47 SortSam Read 10,000,000 records. Elapsed time: 00:03:44s. Time for last 10,000,000: 224s. Last read position: chr11:16,156,478
INFO 2019-06-27 11:34:18 SortSam Read 20,000,000 records. Elapsed time: 00:07:15s. Time for last 10,000,000: 211s. Last read position: chrX:81,543,144
INFO 2019-06-27 11:37:45 SortSam Read 30,000,000 records. Elapsed time: 00:10:41s. Time for last 10,000,000: 206s. Last read position: chr5:25,537,708
INFO 2019-06-27 11:41:06 SortSam Read 40,000,000 records. Elapsed time: 00:14:03s. Time for last 10,000,000: 201s. Last read position: chr2:41,271,687
INFO 2019-06-27 11:44:29 SortSam Read 50,000,000 records. Elapsed time: 00:17:25s. Time for last 10,000,000: 202s. Last read position: chr1:7,845,412
INFO 2019-06-27 11:47:50 SortSam Read 60,000,000 records. Elapsed time: 00:20:47s. Time for last 10,000,000: 201s. Last read position: chr11:21,895,413
INFO 2019-06-27 11:51:14 SortSam Read 70,000,000 records. Elapsed time: 00:24:11s. Time for last 10,000,000: 203s. Last read position: chr4:131,211,260
INFO 2019-06-27 11:54:36 SortSam Read 80,000,000 records. Elapsed time: 00:27:33s. Time for last 10,000,000: 202s. Last read position: chr18:15,256,349
INFO 2019-06-27 11:58:00 SortSam Read 90,000,000 records. Elapsed time: 00:30:57s. Time for last 10,000,000: 204s. Last read position: chr8:43,011,121
INFO 2019-06-27 12:01:20 SortSam Read 100,000,000 records. Elapsed time: 00:34:17s. Time for last 10,000,000: 199s. Last read position: chr3:67,461,633
INFO 2019-06-27 12:04:40 SortSam Read 110,000,000 records. Elapsed time: 00:37:37s. Time for last 10,000,000: 199s. Last read position: chr1:208,356,656
INFO 2019-06-27 12:08:01 SortSam Read 120,000,000 records. Elapsed time: 00:40:57s. Time for last 10,000,000: 200s. Last read position: chr8:36,597,932
INFO 2019-06-27 12:11:15 SortSam Read 130,000,000 records. Elapsed time: 00:44:12s. Time for last 10,000,000: 194s. Last read position: chr4:13,877,909
INFO 2019-06-27 12:14:30 SortSam Read 140,000,000 records. Elapsed time: 00:47:27s. Time for last 10,000,000: 195s. Last read position: chr12:24,958,932
INFO 2019-06-27 12:17:48 SortSam Read 150,000,000 records. Elapsed time: 00:50:45s. Time for last 10,000,000: 197s. Last read position: chrM:12,029
INFO 2019-06-27 12:21:02 SortSam Read 160,000,000 records. Elapsed time: 00:53:59s. Time for last 10,000,000: 194s. Last read position: chr19:51,389,646
INFO 2019-06-27 12:24:22 SortSam Read 170,000,000 records. Elapsed time: 00:57:18s. Time for last 10,000,000: 199s. Last read position: chr11:60,471,707
INFO 2019-06-27 12:27:35 SortSam Read 180,000,000 records. Elapsed time: 01:00:32s. Time for last 10,000,000: 193s. Last read position: chr18:37,730,917
INFO 2019-06-27 12:30:45 SortSam Read 190,000,000 records. Elapsed time: 01:03:42s. Time for last 10,000,000: 190s. Last read position: chr2:189,383,184
INFO 2019-06-27 12:33:59 SortSam Read 200,000,000 records. Elapsed time: 01:06:55s. Time for last 10,000,000: 193s. Last read position: chrX:54,117,879
INFO 2019-06-27 12:37:12 SortSam Read 210,000,000 records. Elapsed time: 01:10:09s. Time for last 10,000,000: 193s. Last read position: chr6:117,707,801
INFO 2019-06-27 12:40:31 SortSam Read 220,000,000 records. Elapsed time: 01:13:28s. Time for last 10,000,000: 198s. Last read position: chr7:40,259,348
INFO 2019-06-27 12:43:42 SortSam Read 230,000,000 records. Elapsed time: 01:16:39s. Time for last 10,000,000: 191s. Last read position: chr6:60,368,991
INFO 2019-06-27 12:47:04 SortSam Read 240,000,000 records. Elapsed time: 01:20:01s. Time for last 10,000,000: 202s. Last read position: chr7:97,522,104
INFO 2019-06-27 12:50:17 SortSam Read 250,000,000 records. Elapsed time: 01:23:14s. Time for last 10,000,000: 193s. Last read position: chr2:183,863,416
INFO 2019-06-27 12:53:34 SortSam Read 260,000,000 records. Elapsed time: 01:26:30s. Time for last 10,000,000: 196s. Last read position: chr4:186,797,102
INFO 2019-06-27 12:56:46 SortSam Read 270,000,000 records. Elapsed time: 01:29:42s. Time for last 10,000,000: 191s. Last read position: chr1:245,650,528
INFO 2019-06-27 12:59:59 SortSam Read 280,000,000 records. Elapsed time: 01:32:56s. Time for last 10,000,000: 193s. Last read position: chr5:49,661,736
INFO 2019-06-27 13:03:15 SortSam Read 290,000,000 records. Elapsed time: 01:36:12s. Time for last 10,000,000: 195s. Last read position: chr2:182,079,455
INFO 2019-06-27 13:06:28 SortSam Read 300,000,000 records. Elapsed time: 01:39:25s. Time for last 10,000,000: 193s. Last read position: chr3:144,473,574
INFO 2019-06-27 13:09:46 SortSam Read 310,000,000 records. Elapsed time: 01:42:43s. Time for last 10,000,000: 197s. Last read position: chr1:188,232,685
INFO 2019-06-27 13:12:58 SortSam Read 320,000,000 records. Elapsed time: 01:45:55s. Time for last 10,000,000: 192s. Last read position: chr10:30,354,172
INFO 2019-06-27 13:16:11 SortSam Read 330,000,000 records. Elapsed time: 01:49:08s. Time for last 10,000,000: 193s. Last read position: chr13:81,382,372
INFO 2019-06-27 13:19:24 SortSam Read 340,000,000 records. Elapsed time: 01:52:21s. Time for last 10,000,000: 192s. Last read position: chr5:14,308,576
INFO 2019-06-27 13:22:43 SortSam Read 350,000,000 records. Elapsed time: 01:55:40s. Time for last 10,000,000: 199s. Last read position: chr19:29,990,711
INFO 2019-06-27 13:26:02 SortSam Read 360,000,000 records. Elapsed time: 01:58:59s. Time for last 10,000,000: 198s. Last read position: chr2:37,155,182
INFO 2019-06-27 13:29:20 SortSam Read 370,000,000 records. Elapsed time: 02:02:16s. Time for last 10,000,000: 197s. Last read position: chr17:40,221,149
INFO 2019-06-27 13:32:33 SortSam Read 380,000,000 records. Elapsed time: 02:05:30s. Time for last 10,000,000: 193s. Last read position: chr8:91,866,066
INFO 2019-06-27 13:35:55 SortSam Read 390,000,000 records. Elapsed time: 02:08:52s. Time for last 10,000,000: 202s. Last read position: chr1:238,639,401
INFO 2019-06-27 13:39:12 SortSam Read 400,000,000 records. Elapsed time: 02:12:09s. Time for last 10,000,000: 196s. Last read position: chr4:124,779,797
INFO 2019-06-27 13:42:31 SortSam Read 410,000,000 records. Elapsed time: 02:15:28s. Time for last 10,000,000: 198s. Last read position: chr11:112,651,705
INFO 2019-06-27 13:45:50 SortSam Read 420,000,000 records. Elapsed time: 02:18:47s. Time for last 10,000,000: 198s. Last read position: chr13:16,137,004
INFO 2019-06-27 13:49:09 SortSam Read 430,000,000 records. Elapsed time: 02:22:06s. Time for last 10,000,000: 199s. Last read position: chr9:63,411,821
INFO 2019-06-27 13:52:28 SortSam Read 440,000,000 records. Elapsed time: 02:25:25s. Time for last 10,000,000: 199s. Last read position: chr6:92,922,749
INFO 2019-06-27 13:55:50 SortSam Read 450,000,000 records. Elapsed time: 02:28:47s. Time for last 10,000,000: 201s. Last read position: chr3:8,587,800
INFO 2019-06-27 13:59:02 SortSam Read 460,000,000 records. Elapsed time: 02:31:59s. Time for last 10,000,000: 192s. Last read position: chr11:45,771,716
INFO 2019-06-27 14:02:19 SortSam Read 470,000,000 records. Elapsed time: 02:35:16s. Time for last 10,000,000: 197s. Last read position: chr11:10,042,847
INFO 2019-06-27 14:05:37 SortSam Read 480,000,000 records. Elapsed time: 02:38:33s. Time for last 10,000,000: 197s. Last read position: chr9:41,288,269
INFO 2019-06-27 14:08:56 SortSam Read 490,000,000 records. Elapsed time: 02:41:52s. Time for last 10,000,000: 199s. Last read position: chr22:25,158,262
INFO 2019-06-27 14:12:09 SortSam Read 500,000,000 records. Elapsed time: 02:45:05s. Time for last 10,000,000: 193s. Last read position: chr11:121,660,544
INFO 2019-06-27 14:15:26 SortSam Read 510,000,000 records. Elapsed time: 02:48:23s. Time for last 10,000,000: 197s. Last read position: chrUn_JTFH01001680v1_decoy:308
INFO 2019-06-27 14:18:37 SortSam Read 520,000,000 records. Elapsed time: 02:51:34s. Time for last 10,000,000: 191s. Last read position: chr10:77,976,905
INFO 2019-06-27 14:21:58 SortSam Read 530,000,000 records. Elapsed time: 02:54:55s. Time for last 10,000,000: 200s. Last read position: chr3:146,498,145
INFO 2019-06-27 14:25:15 SortSam Read 540,000,000 records. Elapsed time: 02:58:12s. Time for last 10,000,000: 197s. Last read position: chr1:11,109,355
INFO 2019-06-27 14:28:32 SortSam Read 550,000,000 records. Elapsed time: 03:01:28s. Time for last 10,000,000: 196s. Last read position: chr13:78,534,071
INFO 2019-06-27 14:31:51 SortSam Read 560,000,000 records. Elapsed time: 03:04:48s. Time for last 10,000,000: 199s. Last read position: chr4:94,783,117
INFO 2019-06-27 14:35:09 SortSam Read 570,000,000 records. Elapsed time: 03:08:05s. Time for last 10,000,000: 197s. Last read position: chr12:27,832,750
INFO 2019-06-27 14:38:26 SortSam Read 580,000,000 records. Elapsed time: 03:11:23s. Time for last 10,000,000: 197s. Last read position: chr22:46,610,396
INFO 2019-06-27 14:41:41 SortSam Read 590,000,000 records. Elapsed time: 03:14:38s. Time for last 10,000,000: 194s. Last read position: chr7:67,623,015
INFO 2019-06-27 14:44:55 SortSam Read 600,000,000 records. Elapsed time: 03:17:52s. Time for last 10,000,000: 193s. Last read position: chr6:124,821,007
INFO 2019-06-27 14:48:06 SortSam Read 610,000,000 records. Elapsed time: 03:21:03s. Time for last 10,000,000: 191s. Last read position: chr3:102,469,660
INFO 2019-06-27 14:51:21 SortSam Read 620,000,000 records. Elapsed time: 03:24:18s. Time for last 10,000,000: 195s. Last read position: chr4:98,389,583
INFO 2019-06-27 14:54:38 SortSam Read 630,000,000 records. Elapsed time: 03:27:35s. Time for last 10,000,000: 196s. Last read position: chr2:94,194,348
INFO 2019-06-27 14:57:58 SortSam Read 640,000,000 records. Elapsed time: 03:30:54s. Time for last 10,000,000: 199s. Last read position: chr12:63,046,766
INFO 2019-06-27 15:01:15 SortSam Read 650,000,000 records. Elapsed time: 03:34:12s. Time for last 10,000,000: 197s. Last read position: chr2:5,409,306
INFO 2019-06-27 15:04:33 SortSam Read 660,000,000 records. Elapsed time: 03:37:29s. Time for last 10,000,000: 197s. Last read position: chr7:80,818,885
INFO 2019-06-27 15:07:49 SortSam Read 670,000,000 records. Elapsed time: 03:40:45s. Time for last 10,000,000: 196s. Last read position: chr1:77,751,996
INFO 2019-06-27 15:11:06 SortSam Read 680,000,000 records. Elapsed time: 03:44:02s. Time for last 10,000,000: 197s. Last read position: chr15:49,864,177
INFO 2019-06-27 15:14:22 SortSam Read 690,000,000 records. Elapsed time: 03:47:18s. Time for last 10,000,000: 196s. Last read position: chr21:34,175,889
INFO 2019-06-27 15:17:45 SortSam Read 700,000,000 records. Elapsed time: 03:50:42s. Time for last 10,000,000: 203s. Last read position: chr20:2,055,236
INFO 2019-06-27 15:21:01 SortSam Read 710,000,000 records. Elapsed time: 03:53:58s. Time for last 10,000,000: 196s. Last read position: chr6:124,232,124
INFO 2019-06-27 15:24:22 SortSam Read 720,000,000 records. Elapsed time: 03:57:19s. Time for last 10,000,000: 200s. Last read position: chr19:45,061,737
INFO 2019-06-27 15:27:39 SortSam Read 730,000,000 records. Elapsed time: 04:00:35s. Time for last 10,000,000: 196s. Last read position: chr14:47,820,215
INFO 2019-06-27 15:30:49 SortSam Finished reading inputs, merging and writing to output now.
INFO 2019-06-27 15:30:49 SortingCollection Creating merging iterator from 1480 files
Using GATK jar /gatk/gatk-package-4.1.0.0-local.jar
Running:
java -Dsamjdk.use_async_io_read_samtools=false -Dsamjdk.use_async_io_write_samtools=true -Dsamjdk.use_async_io_write_tribble=false -Dsamjdk.compression_level=2 -Dsamjdk.compression_level=5 -Xms4000m -jar /gatk/gatk-package-4.1.0.0-local.jar SortSam --INPUT /cromwell_root/fc-2c60522a-326b-4267-94c5-f21b05441fc1/f9a48e87-a052-422b-b8ca-7c160d61392c/PreProcessingForVariantDiscovery_GATK4/ff1c88fa-ca88-427b-96f1-6377d32b1f48/call-MarkDuplicates/HDF111iPS501_D13_r2.hg38.aligned.unsorted.duplicates_marked.bam --OUTPUT /dev/stdout --SORT_ORDER coordinate --CREATE_INDEX false --CREATE_MD5_FILE false
[Thu Jun 27 15:31:30 UTC 2019] picard.sam.SetNmMdAndUqTags done. Elapsed time: 244.49 minutes.
Runtime.totalMemory()=506986496
To get help, see http://broadinstitute.github.io/picard/index.html#GettingHelp
htsjdk.samtools.FileTruncatedException: Premature end of file: data stream
at htsjdk.samtools.util.BlockCompressedInputStream.processNextBlock(BlockCompressedInputStream.java:530)
at htsjdk.samtools.util.BlockCompressedInputStream.nextBlock(BlockCompressedInputStream.java:468)
at htsjdk.samtools.util.BlockCompressedInputStream.readBlock(BlockCompressedInputStream.java:458)
at htsjdk.samtools.util.BlockCompressedInputStream.available(BlockCompressedInputStream.java:196)
at htsjdk.samtools.util.BlockCompressedInputStream.read(BlockCompressedInputStream.java:331)
at java.io.DataInputStream.read(DataInputStream.java:149)
at htsjdk.samtools.util.BinaryCodec.readBytesOrFewer(BinaryCodec.java:421)
at htsjdk.samtools.util.BinaryCodec.readBytes(BinaryCodec.java:394)
at htsjdk.samtools.util.BinaryCodec.readBytes(BinaryCodec.java:380)
at htsjdk.samtools.BAMRecordCodec.decode(BAMRecordCodec.java:268)
at htsjdk.samtools.BAMFileReader$BAMFileIterator.getNextRecord(BAMFileReader.java:838)
at htsjdk.samtools.BAMFileReader$BAMFileIterator.advance(BAMFileReader.java:812)
at htsjdk.samtools.BAMFileReader$BAMFileIterator.next(BAMFileReader.java:806)
at htsjdk.samtools.BAMFileReader$BAMFileIterator.next(BAMFileReader.java:774)
at htsjdk.samtools.SamReader$AssertingIterator.next(SamReader.java:569)
at htsjdk.samtools.SamReader$AssertingIterator.next(SamReader.java:548)
at java.util.Iterator.forEachRemaining(Iterator.java:116)
at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)
at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418)
at picard.sam.SetNmMdAndUqTags.doWork(SetNmMdAndUqTags.java:141)
at picard.cmdline.CommandLineProgram.instanceMain(CommandLineProgram.java:295)
at org.broadinstitute.hellbender.cmdline.PicardCommandLineProgramExecutor.instanceMain(PicardCommandLineProgramExecutor.java:25)
at org.broadinstitute.hellbender.Main.runCommandLineProgram(Main.java:162)
at org.broadinstitute.hellbender.Main.mainEntry(Main.java:205)
at org.broadinstitute.hellbender.Main.main(Main.java:291)
Using GATK jar /gatk/gatk-package-4.1.0.0-local.jar
Running:
java -Dsamjdk.use_async_io_read_samtools=false -Dsamjdk.use_async_io_write_samtools=true -Dsamjdk.use_async_io_write_tribble=false -Dsamjdk.compression_level=2 -Dsamjdk.compression_level=5 -Xms500m -jar /gatk/gatk-package-4.1.0.0-local.jar SetNmMdAndUqTags --INPUT /dev/stdin --OUTPUT HDF111iPS501_D13_r2.hg38.aligned.duplicate_marked.sorted.bam --CREATE_INDEX true --CREATE_MD5_FILE true --REFERENCE_SEQUENCE /cromwell_root/broad-references/hg38/v0/Homo_sapiens_assembly38.fasta

Comments

4 comments

  • Comment author
    Beri

    Hi Aspen,

    What is the name of your workspace? 

    0
  • Comment author
    Aspen Neuro

    Woops, forgot to include it. 

    It is "pd-wgs-workspace", in the project "pd-wgs-project". 

    0
  • Comment author
    Beri
    • Edited

    The error you've listed isn't originating for Terra/Firecloud, its a message coming from the GATK tool, you'll be less likely to find tool errors on this forum. Instead you could try looking for error message on the GATK forum. After searching this message on the forum I came across this post: https://gatkforums.broadinstitute.org/gatk/discussion/5320/erroneous-bam-file-from-indel-realigner

    In the SortAndFixTags task there are two GATK commands, SortSam and SetNmMdAndUqTags. The GATK error above is coming from SetNmMdAndUqTags, so i would assume SortSam is ending prematurely. 

    I can't say for sure what could be wrong, but I've had issues with this task before during a update to Terra a few months back. Increasing the memory helped solve the issue, the suggested memory size is listed in the featured workspace: Germline-SNPs-Indels-GATK4-hg38. I just updated the configurations under the featured tools method repo to reflect the suggestion the memory size. 

    SortAndFixTags

    java_opt_fix "-Xms600m"
    java_opt_sort "-Xms6000m"
    mem_size "7500 MB"
    1
  • Comment author
    Aspen Neuro

    Thank you! That fix worked for me. 

    0

Please sign in to leave a comment.